Open Stack

Does adding a Before=NetworkManager.service into the service file for
glean-nm.service help with the ordering, perhaps?

-Jay Faulkner

On Wed, Mar 17, 2021 at 8:55 AM Dmitry Tantsur <dtantsur at redhat.com> wrote:

> Hi,
>
> Getting back to this, sorry for the delay. Yes, I'm pretty sure it's
> NetworkManager, not something else. Here are relevant parts of boot logs
> from a recent runs:
>
> [   63.613821] NetworkManager[244]: <info>  [1615995259.7778]
> NetworkManager (version 1.26.0-12.el8_3) is starting... (for the first time)
> [   71.637264] systemd[1]: Starting Glean for interface enp1s0 with
> NetworkManager...
>          Starting Glean for interface enp1s0 with NetworkManager...
> [   77.622901] glean.sh[327]: mount: /mnt/config: /dev/sr0 already mounted
> on /mnt/config.
>
> !!! As you see, Glean starts quite early, but then... !!!
>
> [   92.699494] NetworkManager[244]: <info>  [1615995288.9848] manager:
> (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
> [   93.040232] NetworkManager[244]: <info>  [1615995289.3256] manager:
> (enp1s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
> [   94.434450] NetworkManager[244]: <info>  [1615995290.7198] device
> (enp1s0): state change: unmanaged -> unavailable (reason 'managed',
> sys-iface-state: 'external')
> [   94.713545] NetworkManager[244]: <info>  [1615995290.9986] device
> (enp1s0): carrier: link connected
> [   96.487825] NetworkManager[244]: <info>  [1615995292.7699] device
> (enp1s0): state change: unavailable -> disconnected (reason 'none',
> sys-iface-state: 'managed')
> [   96.712608] NetworkManager[244]: <info>  [1615995292.9979] policy:
> auto-activating connection 'Wired connection 1'
> (cabef811-9cf9-3d92-9391-95712a3d3481)
>
> !!! This auto-activation triggers DHCP !!!
>
> [   97.789768] NetworkManager[244]: <info>  [1615995294.0750] device
> (enp1s0): state change: config -> ip-config (reason 'none',
> sys-iface-state: 'managed')
> [   98.084735] NetworkManager[244]: <info>  [1615995294.3699] dhcp4
> (enp1s0): activation: beginning transaction (timeout in 30 seconds)
> [   98.303574] NetworkManager[244]: <info>  [1615995294.5883] dhcp4
> (enp1s0): dhclient started with pid 382
> [  108.882870] NetworkManager[244]: <info>  [1615995305.0369] dhcp4
> (enp1s0):   address 192.168.122.105
>
> !!! 10 seconds later we have the IP address configured !!!
>
> [  126.636082] glean.sh[326]: DEBUG:glean:Starting glean
> [  127.885587] glean.sh[326]: DEBUG:glean:Only considering interface
> enp1s0 from arguments
> [  127.908001] glean.sh[326]: DEBUG:glean:Interface matched: enp1s0
> (52:54:00:9e:b1:16)
> [  127.920045] glean.sh[326]: DEBUG:glean:52:54:00:9e:b1:16 configured via
> config-drive
> [  128.635484] systemd[1]: Started Glean for interface enp1s0 with
> NetworkManager.
>
> !!! 20 seconds later (it's a nested VM, everything is slow) glean actually
> kicks in !!!
>
> [  130.752564] systemd[1]: Reached target Network is Online.
>
> At this point the IP address is from DHCP, not from Glean.
>
> Any ideas?
>
> Dmitry
>
> On Thu, Nov 26, 2020 at 2:20 AM Ian Wienand <iwienand at redhat.com> wrote:
>
>> On Wed, Nov 25, 2020 at 11:54:13AM +0100, Dmitry Tantsur wrote:
>> >
>> > # systemd-analyze critical-chain
>> > multi-user.target @2min 6.301s
>> > └─tuned.service @1min 32.273s +34.024s
>> >   └─network.target @1min 31.590s
>> >     └─network-pre.target @1min 31.579s
>> >       └─glean at enp1s0.service @36.594s +54.952s
>> >         └─system-glean.slice @36.493s
>> >           └─system.slice @4.083s
>> >             └─-.slice @4.080s
>> >
>> > # systemd-analyze critical-chain NetworkManager.service
>> > NetworkManager.service +9.287s
>> > └─network-pre.target @1min 31.579s
>> >   └─glean at enp1s0.service @36.594s +54.952s
>> >     └─system-glean.slice @36.493s
>> >       └─system.slice @4.083s
>> >         └─-.slice @4.080s
>>
>> > It seems that the ordering is correct and the interface service is
>> > executed, but the IP address is nonetheless wrong.
>>
>> I agree, this seems to say to me that NetworkManager should run after
>> network.pre-target, and glean at enp1s0 should be running before it.
>>
>> The glean at enp1s0.service is set as oneshot [1] which should prevent
>> network-pre.target being reached until it exits:
>>
>>  oneshot ... [the] service manager will consider the unit up after the
>>  main process exits. It will then start follow-up units.
>>
>> To the best of my knowledge the dependencies are correct; but if you
>> go through the "git log" of the project you can find some history of
>> us thinking ordering was correct and finding issues.
>>
>> > Can it be related to how long glean takes to run in my case (54 seconds
>> vs
>> > 1 second in your case)?
>>
>> The glean script doesn't run asynchronously in any way (at least not
>> on purpose!).  I can't see any way it could exit before the ifcfg file
>> is written out.
>>
>> > # cat /etc/sysconfig/network-scripts/ifcfg-enp1s0
>> ...
>>
>> The way NM support works is writing out this file which is read by the
>> NM ifcfg-rh plugin [2].  AFAIK that's built-in to NM so would not be
>> missing, and I think you'd have to go to effort to manually edit
>> /etc/NetworkManager/conf.d/99-main-plugins.conf to have it ignored.
>>
>> I'm afraid that's overall not much help.  Are you sure there isn't an
>> errant dhclient running somehow that grabs a different address?  Does
>> it get the correct address on reboot; implying the ifcfg- file is read
>> correctly but somehow isn't in place before NetworkManager starts?
>>
>> -i
>>
>> [1]
>> https://opendev.org/opendev/glean/src/branch/master/glean/init/glean-nm@.service#L13
>> <https://urldefense.proofpoint.com/v2/url?u=https-3A__opendev.org_opendev_glean_src_branch_master_glean_init_glean-2Dnm-40.service-23L13&d=DwMFaQ&c=sWW_bEwW_mLyN3Kx2v57Q8e-CRbmiT9yOhqES_g_wVY&r=NKR1jXf8to59hDGraABDUb4djWcsAXM11_v4c7uz0Tg&m=BrbOLly0UyDhmVy0bJISbRK1Y5YrrOvNg1YCCD5SHvU&s=eRQWThy8wzWvvv_lev73UOEHtOuiSRAKAt13jOs8H14&e=>
>> [2]
>> https://developer.gnome.org/NetworkManager/stable/nm-settings-ifcfg-rh.html
>> <https://urldefense.proofpoint.com/v2/url?u=https-3A__developer.gnome.org_NetworkManager_stable_nm-2Dsettings-2Difcfg-2Drh.html&d=DwMFaQ&c=sWW_bEwW_mLyN3Kx2v57Q8e-CRbmiT9yOhqES_g_wVY&r=NKR1jXf8to59hDGraABDUb4djWcsAXM11_v4c7uz0Tg&m=BrbOLly0UyDhmVy0bJISbRK1Y5YrrOvNg1YCCD5SHvU&s=ULChg-xvPrW8321vs7PAPO57zpkIrWti2rJm3MBWWrI&e=>
>>
>>
>
> --
> Red Hat GmbH, https://de.redhat.com/
> <https://urldefense.proofpoint.com/v2/url?u=https-3A__de.redhat.com_&d=DwMFaQ&c=sWW_bEwW_mLyN3Kx2v57Q8e-CRbmiT9yOhqES_g_wVY&r=NKR1jXf8to59hDGraABDUb4djWcsAXM11_v4c7uz0Tg&m=BrbOLly0UyDhmVy0bJISbRK1Y5YrrOvNg1YCCD5SHvU&s=QKfW3tIDICS7UVtyuyyoIZI2Qd6Y3XdZMQJmfjYY1Ls&e=>
> , Registered seat: Grasbrunn,
> Commercial register: Amtsgericht Muenchen, HRB 153243,
> Managing Directors: Charles Cachera, Brian Klemm, Laurie Krebs, Michael
> O'Neill
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack-discuss/attachments/20210317/f421885f/attachment-0001.html>