Since the update to version 24.04 coming from 23.10, I have noticed waiting times in some situations that did not exist in this form before. The most noticeable and annoying is at system startup. The NetworkManager service appears in the critical path of the systemd analysis with a runtime of just over a minute.
graphical.target @1min 9.538s
└─multi-user.target @1min 9.538s
└─postfix.service @1min 9.536s +1ms
└─[email protected] @1min 8.788s +733ms
└─network-online.target @1min 8.731s
└─NetworkManager-wait-online.service @1min 5.167s +3.562s
└─NetworkManager.service @3.571s +1min 1.586s
└─dbus.service @2.875s +354ms
└─basic.target @2.861s
└─sockets.target @2.861s
└─snapd.socket @2.859s +1ms
└─sysinit.target @2.852s
└─systemd-backlight@backlight:intel_backlight.service @3.601s +76ms
└─system-systemd\x2dbacklight.slice @3.558s
└─system.slice @777ms
└─-.slice @777ms
At first I searched in the NetworkManger context. I deleted connections and set them up again, reinstalled the package, removed IfUpDown. None of this had any negative effects on the connection, but nothing changed in terms of the waiting time.
Then I installed a snap package as a test. Snap is not my favorite, but with Ubuntu it's probably hard to avoid it completely. Anyway, when I installed the Hello package, I also had this waiting time of about a minute. Then I noticed these reload requests to systemd in the log. In the log from June 12th, there are exactly three times, with the NetworkManger, with the installation from the snap store and finally with a unit [email protected], which I cannot currently assign to any observation.
Jun 12 09:10:26 uENVY systemd[1]: Reloading requested from client PID 1244 ('systemctl') (unit NetworkManager.service)...
Jun 12 09:10:26 uENVY systemd[1]: Reloading...
Jun 12 09:10:30 uENVY ModemManager[1151]: <msg> [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0': not supported by any plugin
Jun 12 09:10:54 uENVY systemd-journald[298]: Forwarding to syslog missed 839 messages.
Jun 12 09:10:59 uENVY snapd[953]: stateengine.go:149: state ensure error: Get "https://api.snapcraft.io/api/v1/snaps/sections": dial tcp: lookup api.snapcraft.io on 127.0.0.53:53: server misbehaving
Jun 12 09:10:59 uENVY dbus-daemon[848]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=953 comm="/usr/lib/snapd/snapd" label="unconfined")
Jun 12 09:11:24 uENVY dbus-daemon[848]: [system] Failed to activate service 'org.freedesktop.timedate1': timed out (service_start_timeout=25000ms)
Jun 12 09:11:24 uENVY dbus-daemon[848]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=953 comm="/usr/lib/snapd/snapd" label="unconfined")
Jun 12 09:11:27 uENVY systemd[1]: /etc/systemd/system/teamviewerd.service:9: PIDFile= references a path below legacy directory /var/run/, updating /var/run/teamviewerd.pid → /run/teamviewerd.pid; please update the unit file accordingly.
Jun 12 09:11:27 uENVY systemd[1]: Reloading finished in 60479 ms.
...
Jun 12 11:30:10 uENVY systemd[1]: Reloading requested from client PID 12854 ('systemctl') (unit snapd.service)...
Jun 12 11:30:10 uENVY systemd[1]: Reloading...
Jun 12 11:30:16 uENVY NetworkManager[1078]: <debug> [1718184616.3455] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 11:30:53 uENVY NetworkManager[1078]: <debug> [1718184653.7845] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 11:30:57 uENVY NetworkManager[1078]: <debug> [1718184657.3063] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1256] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1257] ndisc-lndp[0x59681f664af0,"wlp1s0"]: received router advertisement at timestamp 8433.122 seconds
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1258] ndisc[0x59681f664af0,"wlp1s0"]: router-data: next lifetime expiration will happen: in 1200,000 seconds
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1258] ndisc[0x59681f664af0,"wlp1s0"]: neighbor discovery configuration changed [GARS]:
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1258] ndisc[0x59681f664af0,"wlp1s0"]: dhcp-level otherconf
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1259] ndisc[0x59681f664af0,"wlp1s0"]: hop limit : 255
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1259] ndisc[0x59681f664af0,"wlp1s0"]: gateway fe80::a96:d7ff:fe51:3678 pref medium exp 1800,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1260] ndisc[0x59681f664af0,"wlp1s0"]: address 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080 exp 7200,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1261] ndisc[0x59681f664af0,"wlp1s0"]: route 2001:16b8:6c7e:a300::/56 via fe80::a96:d7ff:fe51:3678 pref medium exp 1800,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1262] ndisc[0x59681f664af0,"wlp1s0"]: route 2001:16b8:6c7e:a300::/64 via :: pref medium exp 7200,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1262] ndisc[0x59681f664af0,"wlp1s0"]: dns_server fd00::a96:d7ff:fe51:3678 exp 1200,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1263] ndisc[0x59681f664af0,"wlp1s0"]: dns_server 2001:16b8:6c7e:a300:a96:d7ff:fe51:3678 exp 1200,000
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1265] ndisc[0x59681f664af0,"wlp1s0"]: solicit: schedule sending next (slow) solicitation in about 1143,012 seconds
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1268] l3cfg[a0ce3e31d0faf303,ifindex=2]: obj-state: update: [212be299a048d1af, ip6-address, 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080/64 lft 7200sec pref 3600sec lifetime 8433-8433[3600,7200] dev 2 flags mngtmpaddr,noprefixroute src ndisc], nm-configured, in-platform (static: 1, dynamic: 0)
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1268] dns-mgr: (device_l3cd_changed): queueing DNS updates (1)
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1269] dns-mgr: (device_l3cd_changed): DNS configuration did not change
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1269] dns-mgr: (device_l3cd_changed): no DNS changes to commit (0)
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1273] platform: (wlp1s0) address: adding or updating IPv6 address: 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080/64 lft 7200sec pref 3600sec lifetime 8433-0[3600,7200] dev 2 flags mngtmpaddr,noprefixroute src unknown
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1275] platform: (wlp1s0) signal: address 6 changed: 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080/64 lft 7200sec pref 3600sec lifetime 8433-8432[3601,7201] dev 2 flags mngtmpaddr,noprefixroute src kernel
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1276] l3cfg[a0ce3e31d0faf303,ifindex=2]: obj-state: appeared in platform: [212be299a048d1af, ip6-address, 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080/64 lft 7200sec pref 3600sec lifetime 8433-8433[3600,7200] dev 2 flags mngtmpaddr,noprefixroute src ndisc], nm-configured, in-platform
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1278] platform: (wlp1s0) signal: address 6 changed: 2001:16b8:6c7e:a300:37ed:ec07:1f63:cdf1/64 lft 7200sec pref 3600sec lifetime 8433-8432[3601,7201] dev 2 flags secondary src kernel
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.1279] platform-linux: do-add-ip6-address[2: 2001:16b8:6c7e:a300:8f:7d3c:18cd:b080]: success
Jun 12 11:30:58 uENVY NetworkManager[1078]: <debug> [1718184658.7877] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 11:31:10 uENVY systemd[1]: /etc/systemd/system/teamviewerd.service:9: PIDFile= references a path below legacy directory /var/run/, updating /var/run/teamviewerd.pid → /run/teamviewerd.pid; please update the unit file accordingly.
Jun 12 11:31:10 uENVY systemd[1]: Reloading finished in 60588 ms.
...
Jun 12 18:36:01 uENVY systemd[1]: Reloading requested from client PID 23092 ('systemctl') (unit [email protected])...
Jun 12 18:36:01 uENVY systemd[1]: Reloading...
Jun 12 18:36:31 uENVY NetworkManager[1078]: <debug> [1718210191.4450] connectivity: (wlp1s0,IPv4,235) start request to 'http://connectivity-check.ubuntu.com./' (try resolving 'connectivity-check.ubuntu.com.' using systemd-resolved)
Jun 12 18:36:31 uENVY NetworkManager[1078]: <debug> [1718210191.5359] connectivity: (wlp1s0,IPv4,235) check completed: FULL; status header found
Jun 12 18:36:36 uENVY NetworkManager[1078]: <debug> [1718210196.5243] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 18:36:36 uENVY NetworkManager[1078]: <debug> [1718210196.9523] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 18:36:37 uENVY NetworkManager[1078]: <debug> [1718210197.4452] connectivity: (wlp1s0,IPv6,236) start request to 'http://connectivity-check.ubuntu.com./' (try resolving 'connectivity-check.ubuntu.com.' using systemd-resolved)
Jun 12 18:36:37 uENVY NetworkManager[1078]: <debug> [1718210197.7391] connectivity: (wlp1s0,IPv6,236) check completed: FULL; status header found
Jun 12 18:36:42 uENVY NetworkManager[1078]: <debug> [1718210202.0547] ndisc-lndp[0x59681f664af0,"wlp1s0"]: processing libndp events
Jun 12 18:36:47 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:47 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:50 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:51 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:51 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:51 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:53 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:36:53 uENVY rtkit-daemon[1467]: Supervising 9 threads of 6 processes of 1 users.
Jun 12 18:37:02 uENVY systemd[1]: /etc/systemd/system/teamviewerd.service:9: PIDFile= references a path below legacy directory /var/run/, updating /var/run/teamviewerd.pid → /run/teamviewerd.pid; please update the unit file accordingly.
Jun 12 18:37:02 uENVY systemd[1]: Reloading finished in 60615 ms.
As you can see, the reload is always completed in almost exactly 60000ms. It doesn't look to me as if this time is really being used here, but rather a kind of deadlock in systemd, which is resolved by a timeout (60s).
Any help with the solution is very appreciated.
