<div dir="ltr">Does adding a Before=NetworkManager.service into the service file for glean-nm.service help with the ordering, perhaps?<div><br></div><div>-Jay Faulkner</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Wed, Mar 17, 2021 at 8:55 AM Dmitry Tantsur <<a href="mailto:dtantsur@redhat.com">dtantsur@redhat.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div>Hi,</div><div><br></div><div>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:</div><div><br></div><div>[ 63.613821] NetworkManager[244]: <info> [1615995259.7778] NetworkManager (version 1.26.0-12.el8_3) is starting... (for the first time)<br>[ 71.637264] systemd[1]: Starting Glean for interface enp1s0 with NetworkManager...<br> Starting Glean for interface enp1s0 with NetworkManager...</div><div>[ 77.622901] glean.sh[327]: mount: /mnt/config: /dev/sr0 already mounted on /mnt/config.</div><div><br></div><div>!!! As you see, Glean starts quite early, but then... !!!<br></div><div><br></div><div></div><div>[ 92.699494] NetworkManager[244]: <info> [1615995288.9848] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)<br>[ 93.040232] NetworkManager[244]: <info> [1615995289.3256] manager: (enp1s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)</div><div>[ 94.434450] NetworkManager[244]: <info> [1615995290.7198] device (enp1s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')<br>[ 94.713545] NetworkManager[244]: <info> [1615995290.9986] device (enp1s0): carrier: link connected</div><div>[ 96.487825] NetworkManager[244]: <info> [1615995292.7699] device (enp1s0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')<br>[ 96.712608] NetworkManager[244]: <info> [1615995292.9979] policy: auto-activating connection 'Wired connection 1' (cabef811-9cf9-3d92-9391-95712a3d3481)</div><div><br></div><div>!!! This auto-activation triggers DHCP !!!<br></div><div><br></div><div>[ 97.789768] NetworkManager[244]: <info> [1615995294.0750] device (enp1s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')<br>[ 98.084735] NetworkManager[244]: <info> [1615995294.3699] dhcp4 (enp1s0): activation: beginning transaction (timeout in 30 seconds)<br>[ 98.303574] NetworkManager[244]: <info> [1615995294.5883] dhcp4 (enp1s0): dhclient started with pid 382</div><div></div><div>[ 108.882870] NetworkManager[244]: <info> [1615995305.0369] dhcp4 (enp1s0): address 192.168.122.105</div><div><br></div><div>!!! 10 seconds later we have the IP address configured !!!</div><div><br></div><div>[ 126.636082] glean.sh[326]: DEBUG:glean:Starting glean</div><div>[ 127.885587] glean.sh[326]: DEBUG:glean:Only considering interface enp1s0 from arguments<br>[ 127.908001] glean.sh[326]: DEBUG:glean:Interface matched: enp1s0 (52:54:00:9e:b1:16)<br>[ 127.920045] glean.sh[326]: DEBUG:glean:52:54:00:9e:b1:16 configured via config-drive</div><div>[ 128.635484] systemd[1]: Started Glean for interface enp1s0 with NetworkManager.</div><div><br></div><div>!!! 20 seconds later (it's a nested VM, everything is slow) glean actually kicks in !!!</div><div><br></div><div>[ 130.752564] systemd[1]: Reached target Network is Online.</div><div><br></div><div>At this point the IP address is from DHCP, not from Glean.</div><div><br></div><div>Any ideas?</div><div><br></div><div>Dmitry<br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, Nov 26, 2020 at 2:20 AM Ian Wienand <<a href="mailto:iwienand@redhat.com" target="_blank">iwienand@redhat.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">On Wed, Nov 25, 2020 at 11:54:13AM +0100, Dmitry Tantsur wrote:<br>
> <br>
> # systemd-analyze critical-chain<br>
> multi-user.target @2min 6.301s<br>
> └─tuned.service @1min 32.273s +34.024s<br>
> └─network.target @1min 31.590s<br>
> └─network-pre.target @1min 31.579s<br>
> └─glean@enp1s0.service @36.594s +54.952s<br>
> └─system-glean.slice @36.493s<br>
> └─system.slice @4.083s<br>
> └─-.slice @4.080s<br>
> <br>
> # systemd-analyze critical-chain NetworkManager.service<br>
> NetworkManager.service +9.287s<br>
> └─network-pre.target @1min 31.579s<br>
> └─glean@enp1s0.service @36.594s +54.952s<br>
> └─system-glean.slice @36.493s<br>
> └─system.slice @4.083s<br>
> └─-.slice @4.080s<br>
<br>
> It seems that the ordering is correct and the interface service is<br>
> executed, but the IP address is nonetheless wrong. <br>
<br>
I agree, this seems to say to me that NetworkManager should run after<br>
network.pre-target, and glean@enp1s0 should be running before it.<br>
<br>
The glean@enp1s0.service is set as oneshot [1] which should prevent<br>
network-pre.target being reached until it exits:<br>
<br>
oneshot ... [the] service manager will consider the unit up after the<br>
main process exits. It will then start follow-up units.<br>
<br>
To the best of my knowledge the dependencies are correct; but if you<br>
go through the "git log" of the project you can find some history of<br>
us thinking ordering was correct and finding issues.<br>
<br>
> Can it be related to how long glean takes to run in my case (54 seconds vs<br>
> 1 second in your case)?<br>
<br>
The glean script doesn't run asynchronously in any way (at least not<br>
on purpose!). I can't see any way it could exit before the ifcfg file<br>
is written out.<br>
<br>
> # cat /etc/sysconfig/network-scripts/ifcfg-enp1s0<br>
...<br>
<br>
The way NM support works is writing out this file which is read by the<br>
NM ifcfg-rh plugin [2]. AFAIK that's built-in to NM so would not be<br>
missing, and I think you'd have to go to effort to manually edit<br>
/etc/NetworkManager/conf.d/99-main-plugins.conf to have it ignored.<br>
<br>
I'm afraid that's overall not much help. Are you sure there isn't an<br>
errant dhclient running somehow that grabs a different address? Does<br>
it get the correct address on reboot; implying the ifcfg- file is read<br>
correctly but somehow isn't in place before NetworkManager starts?<br>
<br>
-i<br>
<br>
[1] <a href="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=" rel="noreferrer" target="_blank">https://opendev.org/opendev/glean/src/branch/master/glean/init/glean-nm@.service#L13</a><br>
[2] <a href="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=" rel="noreferrer" target="_blank">https://developer.gnome.org/NetworkManager/stable/nm-settings-ifcfg-rh.html</a><br>
<br>
</blockquote></div><br clear="all"><br>-- <br><div dir="ltr"><div dir="ltr">Red Hat GmbH, <a href="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=" target="_blank">https://de.redhat.com/</a> , Registered seat: Grasbrunn, <br>Commercial register: Amtsgericht Muenchen, HRB 153243,<br>Managing Directors: Charles Cachera, Brian Klemm, Laurie Krebs, Michael O'Neill <br></div></div>
</blockquote></div>