You are not logged in.

#1 2021-09-16 01:02:09

Cvlc
Member
Registered: 2020-03-26
Posts: 295

[SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Hi

I followed the steps in the wiki to use iwd as the NetworkManager backend, however this breaks NetworkManager_Wait_Online

The network is detected online before it really is :

Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.4266] ovsdb: Impossible de se connecter : Aucun fichier ou dossier de ce type
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.4266] ovsdb: disconnected from ovsdb
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.4270] device (wlan0): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.4282] manager: startup complete
Sep 16 02:49:09 modern15 systemd[1]: Finished Network Manager Wait Online.
Sep 16 02:49:09 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-wait-online comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=su>
Sep 16 02:49:09 modern15 systemd[1]: Reached target Network is Online.
Sep 16 02:49:09 modern15 systemd[1]: Starting Refresh Pacman mirrorlist with Reflector...
Sep 16 02:49:09 modern15 reflector[864]: error: failed to retrieve mirrorstatus data: URLError: <urlopen error [Errno -2] Name or service not known>
Sep 16 02:49:09 modern15 systemd[1]: reflector.service: Main process exited, code=exited, status=1/FAILURE
Sep 16 02:49:09 modern15 systemd[1]: reflector.service: Failed with result 'exit-code'.
Sep 16 02:49:09 modern15 systemd[1]: Failed to start Refresh Pacman mirrorlist with Reflector..
Sep 16 02:49:09 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=reflector comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Sep 16 02:49:09 modern15 systemd[1]: Reached target Multi-User System.
Sep 16 02:49:09 modern15 systemd[1]: Reached target Graphical Interface.
Sep 16 02:49:09 modern15 systemd[1]: Startup finished in 4.021s (firmware) + 230ms (loader) + 763ms (kernel) + 6.012s (initrd) + 1.858s (userspace) = 12.887s.
Sep 16 02:49:09 modern15 NetworkManager[689]: <error> [1631753349.6465] iwd-manager[0x55e139bce990]: IWD device named wlan0 is not a Wifi device
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.6468] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/6)
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.6470] device (wlan0): new IWD device state is disconnected
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.6483] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.6489] device (wlan0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Sep 16 02:49:09 modern15 kernel: wlan0: authenticate with 30:24:78:33:3d:b4
Sep 16 02:49:09 modern15 kernel: wlan0: send auth to 30:24:78:33:3d:b4 (try 1/3)
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.7716] device (wlan0): new IWD device state is connecting
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.7719] device (wlan0): Activation: starting connection 'XXXXXXXXXXXXX'
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.7719] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.7720] manager: NetworkManager state is now CONNECTING
Sep 16 02:49:09 modern15 NetworkManager[689]: <info>  [1631753349.7721] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')

any idea how to fix it ?

Thanks!

Last edited by Cvlc (2021-09-22 22:03:27)

Offline

#2 2021-09-16 10:50:12

solskog
Member
Registered: 2020-09-05
Posts: 462

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Please show your output from

# systemd-analyze blame

Offline

#3 2021-09-16 11:46:07

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Hi,

Thanks for your answer

319ms firewalld.service
286ms initrd-switch-root.service
246ms NetworkManager-wait-online.service
170ms systemd-udev-trigger.service
161ms upower.service
158ms systemd-journal-flush.service
129ms iwd.service
 97ms reflector.service
 87ms bolt.service
 85ms systemd-resolved.service
 70ms lvm2-monitor.service
 62ms initrd-parse-etc.service
 53ms user@60303.service
 47ms power-profiles-daemon.service
 46ms systemd-homed.service
 45ms thermald.service
 45ms systemd-logind.service
 43ms polkit.service
 40ms udisks2.service
 39ms systemd-timesyncd.service
 38ms systemd-oomd.service
 35ms NetworkManager.service
 32ms systemd-fsck@dev-disk-by\x2duuid-F9D6\x2dBC73.service
 28ms systemd-rfkill.service
 28ms systemd-udevd.service
 25ms systemd-tmpfiles-setup-dev.service
 20ms systemd-tmpfiles-setup.service
 20ms systemd-random-seed.service
 19ms systemd-zram-setup@zram0.service
 16ms accounts-daemon.service
 13ms bluetooth.service
 12ms udisks2-zram-setup@zram0.service
 12ms colord.service
 12ms systemd-userdbd.service
 11ms initrd-cleanup.service
  9ms systemd-modules-load.service
  8ms gdm.service
  8ms alsa-restore.service
  8ms systemd-fsck-root.service
  7ms systemd-journald.service
  6ms dev-hugepages.mount
  6ms dev-mqueue.mount
  6ms sys-kernel-debug.mount
  6ms modprobe@fuse.service
  6ms sys-kernel-tracing.mount
  5ms \x2esnapshots.mount
  5ms kmod-static-nodes.service
  5ms home.mount
  5ms initrd-udevadm-cleanup-db.service
  5ms systemd-update-utmp.service
  5ms var.mount
  4ms modprobe@drm.service
  4ms dev-zram0.swap
  4ms boot.mount
  4ms user-runtime-dir@60303.service
  3ms systemd-remount-fs.service
  3ms systemd-backlight@backlight:intel_backlight.service
  2ms systemd-sysctl.service
  2ms systemd-user-sessions.service
  2ms rtkit-daemon.service
  1ms tmp.mount
  1ms sys-kernel-config.mount
  1ms sys-fs-fuse-connections.mount
  1ms modprobe@configfs.service
 62us systemd-homed-activate.service

Offline

#4 2021-09-16 15:11:52

solskog
Member
Registered: 2020-09-05
Posts: 462

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

In my setup, the NetworkManager-wait-online.service actually waited for more then 1 min. But your NetworkManager-wait-online.service reached at 246ms.

solskog wrote:

# systemd-analyze blame
1min 20ms NetworkManager-wait-online.service
    533ms iwd.service
      20ms NetworkManager.service
...
# cat /lib/systemd/system/NetworkManager-wait-online.service
...
Environment=NM_ONLINE_TIMEOUT=60
...

What is your output from

# cat /etc/iwd/main.conf
# cat /etc/NetworkManager/conf.d/wifi_backend.conf
# cat /lib/systemd/systemd/iwd.service

Offline

#5 2021-09-16 15:24:35

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Hi

I have no iwd/main.conf since defaults seemed to be OK

$ cat /etc/NetworkManager/conf.d/wifi_backend.conf
[device]
wifi.backend=iwd
$ cat /lib/systemd/system/iwd.service 
[Unit]
Description=Wireless service
After=network-pre.target
Before=network.target
Wants=network.target

[Service]
Type=dbus
BusName=net.connman.iwd
ExecStart=/usr/lib/iwd/iwd
NotifyAccess=main
LimitNPROC=1
Restart=on-failure
CapabilityBoundingSet=CAP_NET_ADMIN CAP_NET_RAW CAP_NET_BIND_SERVICE
PrivateTmp=true
NoNewPrivileges=true
DevicePolicy=closed
DeviceAllow=/dev/rfkill rw
ProtectHome=yes
ProtectSystem=strict
ProtectControlGroups=yes
ProtectKernelModules=yes
ConfigurationDirectory=iwd
StateDirectory=iwd
StateDirectoryMode=0700

[Install]
WantedBy=multi-user.target

Offline

#6 2021-09-16 15:26:36

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

solskog wrote:

In my setup, the NetworkManager-wait-online.service actually waited for more then 1 min. But your NetworkManager-wait-online.service reached at 246ms.

That's the thing, I initially thought it was a timeout problem but it doesn't timeout, it finishes like the network was up except it isn't connected yet.
worked perfectly with wpa_supplicant

Offline

#7 2021-09-17 03:41:03

solskog
Member
Registered: 2020-09-05
Posts: 462

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Sep 16 02:49:09 modern15 NetworkManager[689]: <error> [1631753349.6465] iwd-manager[0x55e139bce990]: IWD device named wlan0 is not a WiFi device

I can now reproduce this error by placing two config files in the system-connection directory, and one of them is useless placeholder. Once I removed the placeholder, the error went away.

# ls /etc/NetworkManager/system-connections/
profile1.nmconnection
placeholder.nmconnection

Last edited by solskog (2021-09-17 03:48:28)

Offline

#8 2021-09-17 10:07:01

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

I cannot reproduce it anymore, when I search my log it only appears on that occurrence.

However the chain of events is still wrong:

sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: Impossible de se connecter : Aucun fichier ou dossier de ce type
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: disconnected from ovsdb
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1613] device (wlan0): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1629] manager: startup complete
sept. 17 11:44:07 modern15 systemd[1]: Finished Network Manager Wait Online.
sept. 17 11:44:07 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-wait-online comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=>
sept. 17 11:44:07 modern15 systemd[1]: Reached target Network is Online.
sept. 17 11:44:07 modern15 audit: BPF prog-id=47 op=LOAD
sept. 17 11:44:07 modern15 systemd[1]: Starting Refresh Pacman mirrorlist with Reflector....
sept. 17 11:44:07 modern15 systemd[1]: Starting Refresh Pacman mirrorlist with Reflector....
sept. 17 11:44:07 modern15 audit[640]: NETFILTER_CFG table=firewalld:2 family=1 entries=1 op=nft_register_table pid=640 comm="firewalld"
sept. 17 11:44:07 modern15 audit[808]: USER_START pid=808 uid=0 auid=120 ses=1 msg='op=PAM:session_open grantors=pam_loginuid,pam_keyinit,pam_succeed_if,pam_permit,pam_systemd,pam_env acct="gdm" exe="/usr/lib/g>
sept. 17 11:44:07 modern15 systemd[819]: Started D-Bus User Message Bus.
sept. 17 11:44:07 modern15 systemd[819]: Started D-Bus User Message Bus.
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: Impossible de se connecter : Aucun fichier ou dossier de ce type
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: disconnected from ovsdb
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1613] device (wlan0): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1629] manager: startup complete
sept. 17 11:44:07 modern15 systemd[1]: Finished Network Manager Wait Online.
sept. 17 11:44:07 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-wait-online comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=>
sept. 17 11:44:07 modern15 systemd[1]: Reached target Network is Online.
sept. 17 11:44:07 modern15 audit: BPF prog-id=47 op=LOAD
sept. 17 11:44:07 modern15 systemd[1]: Starting Refresh Pacman mirrorlist with Reflector....
sept. 17 11:44:07 modern15 audit[640]: NETFILTER_CFG table=firewalld:2 family=1 entries=1 op=nft_register_table pid=640 comm="firewalld"
sept. 17 11:44:07 modern15 audit[640]: SYSCALL arch=c000003e syscall=46 success=yes exit=84 a0=6 a1=7ffec27b91b0 a2=0 a3=7ffec27a80dc items=0 ppid=1 pid=640 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egi>
sept. 17 11:44:07 modern15 audit: PROCTITLE proctitle=2F7573722F62696E2F707974686F6E002F7573722F62696E2F6669726577616C6C64002D2D6E6F666F726B002D2D6E6F706964
sept. 17 11:44:07 modern15 systemd-udevd[538]: Using default interface naming scheme 'v249'.
sept. 17 11:44:07 modern15 dbus-daemon[639]: [system] Successfully activated service 'org.freedesktop.UPower'
sept. 17 11:44:07 modern15 systemd[1]: Started Daemon for power management.
sept. 17 11:44:07 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=upower comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
sept. 17 11:44:07 modern15 thermald[646]: 27 CPUID levels; family:model:stepping 0x6:8c:1 (6:140:1)
sept. 17 11:44:07 modern15 thermald[646]: Polling mode is enabled: 4
sept. 17 11:44:07 modern15 thermald[646]: sensor id 10 : No temp sysfs for reading raw temp
sept. 17 11:44:07 modern15 thermald[646]: sensor id 10 : No temp sysfs for reading raw temp
sept. 17 11:44:07 modern15 thermald[646]: sensor id 10 : No temp sysfs for reading raw temp
sept. 17 11:44:07 modern15 gnome-session[859]: gnome-session-binary[859]: WARNING: Failed to upload environment to systemd: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.freedesktop.systemd1">
sept. 17 11:44:07 modern15 gnome-session-binary[859]: WARNING: Failed to upload environment to systemd: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.freedesktop.systemd1" does not exist
sept. 17 11:44:07 modern15 gnome-session[859]: gnome-session-binary[859]: WARNING: Failed to reset failed state of units: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.freedesktop.systemd1" d>
sept. 17 11:44:07 modern15 gnome-session-binary[859]: WARNING: Failed to reset failed state of units: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.freedesktop.systemd1" does not exist
sept. 17 11:44:07 modern15 gnome-session-binary[859]: WARNING: Falling back to non-systemd startup procedure due to error: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.freedesktop.systemd1" >
sept. 17 11:44:07 modern15 gnome-session[859]: gnome-session-binary[859]: WARNING: Falling back to non-systemd startup procedure due to error: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Name "org.fr>
sept. 17 11:44:07 modern15 reflector[863]: error: failed to retrieve mirrorstatus data: URLError: <urlopen error [Errno -2] Name or service not known>
sept. 17 11:44:07 modern15 systemd[1]: reflector.service: Main process exited, code=exited, status=1/FAILURE
sept. 17 11:44:07 modern15 systemd[1]: reflector.service: Failed with result 'exit-code'.
sept. 17 11:44:07 modern15 systemd[1]: Failed to start Refresh Pacman mirrorlist with Reflector..
sept. 17 11:44:07 modern15 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=reflector comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
sept. 17 11:44:07 modern15 systemd[1]: Reached target Multi-User System.
sept. 17 11:44:07 modern15 systemd[1]: Reached target Graphical Interface.
sept. 17 11:44:07 modern15 systemd[1]: Startup finished in 3.228s (firmware) + 222ms (loader) + 766ms (kernel) + 8.675s (initrd) + 1.933s (userspace) = 14.826s.
sept. 17 11:44:07 modern15 audit: BPF prog-id=47 op=UNLOAD
sept. 17 11:44:07 modern15 gnome-shell[872]: Adding device '/dev/dri/card0' (i915) using atomic mode setting.
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.3754] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/6)
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.3758] device (wlan0): new IWD device state is disconnected
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.3783] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.3788] device (wlan0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
sept. 17 11:44:07 modern15 audit[640]: NETFILTER_CFG table=firewalld:3 family=1 entries=225 op=nft_register_chain pid=640 comm="firewalld"
sept. 17 11:44:07 modern15 audit[640]: SYSCALL arch=c000003e syscall=46 success=yes exit=24556 a0=6 a1=7ffec27b91b0 a2=0 a3=7ffec27a80dc items=0 ppid=1 pid=640 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 >
sept. 17 11:44:07 modern15 audit: PROCTITLE proctitle=2F7573722F62696E2F707974686F6E002F7573722F62696E2F6669726577616C6C64002D2D6E6F666F726B002D2D6E6F706964
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.5020] device (wlan0): new IWD device state is connecting
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.5024] device (wlan0): Activation: starting connection 'BavWiFi' (35bd3f0d-5ac4-4315-81b7-f156759dcb14)
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.5025] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.5026] manager: NetworkManager state is now CONNECTING
sept. 17 11:44:07 modern15 kernel: wlan0: authenticate with 30:24:78:33:3d:b4
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.5027] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')

the online state is reached before NM connects

Offline

#9 2021-09-18 03:13:29

solskog
Member
Registered: 2020-09-05
Posts: 462

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Cvlc wrote:

sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: Impossible de se connecter : Aucun fichier ou dossier de ce type
sept. 17 11:44:07 modern15 NetworkManager[688]: <info>  [1631871847.1610] ovsdb: disconnected from ovsdb

Are you using a vSwitch with NetworkManger? Is this vSwitch essential for network connectivity for e.g: reflector?

Offline

#10 2021-09-21 00:08:41

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

Hi

I’m not sure what a vSwitch is but from looking at the Wikipedia article I don’t think that I am using one. If I am, it isn’t intentional !

Offline

#11 2021-09-22 21:18:27

Cvlc
Member
Registered: 2020-03-26
Posts: 295

Re: [SOLVED] Iwd backend for NetworkManager 'breaks' NM-wait-online

[EDIT]

OK, ~Solved~ it (sort of)

Found a similar issue. Apparently the NetworkManager-wait-online.service is broken, and has been for a long time. It's a partial fix as it may lead to other problems apparently, but the solution in the link fixes it for my setup :

$ sudo systemctl edit NetworkManager-wait-online.service 

[Service]
ExecStart=
ExecStart=/usr/bin/nm-online -q

Now the wait-online-service waits until the connection is established to terminate

Thanks for your help !

Last edited by Cvlc (2021-09-22 22:02:19)

Offline

Board footer

Powered by FluxBB