Something is holding up NetworkManager-wait-online.service

Finally! Some relevant and actionable output! :slight_smile:

   -- Journal begins at Thu 2021-01-07 05:20:58 EST, ends at Tue 2021-01-26 02:09:51 EST. --
    Jan 26 02:04:48 kernel: __common_interrupt: 1.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 2.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 3.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 4.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 5.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 6.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 7.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 8.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 9.55 No irq handler for vector
    Jan 26 02:04:48 kernel: __common_interrupt: 10.55 No irq handler for vector
    Jan 26 02:04:48 kernel: sd 7:0:0:0: [sdb] No Caching mode page found
    Jan 26 02:04:48 kernel: sd 7:0:0:0: [sdb] Assuming drive cache: write through
    Jan 26 02:04:48 kernel: sd 8:0:0:0: [sdd] No Caching mode page found
    Jan 26 02:04:48 kernel: sd 8:0:0:0: [sdd] Assuming drive cache: write through
    Jan 26 02:04:48 systemd-udevd[611]: nvme0: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[592]: nvme1: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:01.0/0000:04:00.0/nvme/nvme1/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[606]: nvme1n1p3: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:01.0/0000:04:00.0/nvme/nvme1/nvme1n1/nvme1n1p3/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[622]: nvme1n1p1: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:01.0/0000:04:00.0/nvme/nvme1/nvme1n1/nvme1n1p1/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[583]: nvme1n1p2: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:01.0/0000:04:00.0/nvme/nvme1/nvme1n1/nvme1n1p2/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[584]: nvme0n1p2: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/nvme0n1/nvme0n1p2/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[597]: nvme0n1p3: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/nvme0n1/nvme0n1p3/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[619]: nvme0n1p1: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/nvme0n1/nvme0n1p1/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[603]: nvme0n1p4: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/nvme0n1/nvme0n1p4/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[619]: host7: /etc/udev/rules.d/50-sata.rules:3 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:08.0/0000:08:00.3/usb4/4-1/4-1:1.0/host7/scsi_host/host7/link_power_management_policy}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[613]: host9: /etc/udev/rules.d/50-sata.rules:3 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:08.0/0000:08:00.1/usb2/2-4/2-4:1.0/host9/scsi_host/host9/link_power_management_policy}, ignoring: No such file or directory
    Jan 26 02:04:48 systemd-udevd[619]: host8: /etc/udev/rules.d/50-sata.rules:3 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:08.0/0000:08:00.3/usb3/3-2/3-2:1.0/host8/scsi_host/host8/link_power_management_policy}, ignoring: No such file or directory
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 systemd-udevd[599]: nvme0n1p1: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.1/0000:01:00.0/nvme/nvme0/nvme0n1/nvme0n1p1/queue/scheduler}, ignoring: No such file or directory
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:48 kernel: kvm: disabled by bios
    Jan 26 02:04:49 kernel: kvm: disabled by bios
    Jan 26 02:04:49 kernel: 
    Jan 26 02:04:49 kernel: NVRM: loading NVIDIA UNIX x86_64 Kernel Module  455.46.04  Wed Dec 16 18:04:50 UTC 2020
    Jan 26 02:04:49 kernel: kvm: disabled by bios
    Jan 26 02:04:49 bluetoothd[808]: profiles/audio/avctp.c:avctp_server_socket() setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:04:49 bluetoothd[808]: avrcp-controller: Protocol not supported (93)
    Jan 26 02:04:49 bluetoothd[808]: profiles/audio/avctp.c:avctp_server_socket() setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:04:49 bluetoothd[808]: audio-avrcp-target: Protocol not supported (93)
    Jan 26 02:04:49 nmbd[868]: [2021/01/26 02:04:49.533862,  0] ../../lib/util/become_daemon.c:147(daemon_status)
    Jan 26 02:04:49 nmbd[868]:   daemon_status: daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ...
    Jan 26 02:04:49 nmbd[868]: [2021/01/26 02:04:49.534135,  0] ../../source3/nmbd/nmbd_subnetdb.c:253(create_subnets)
    Jan 26 02:04:49 nmbd[868]:   NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6).
    Jan 26 02:04:49 kernel: nvidia-gpu 0000:0b:00.3: i2c timeout error e0000000
    Jan 26 02:04:49 kernel: ucsi_ccg 0-0008: i2c_transfer failed -110
    Jan 26 02:04:49 kernel: ucsi_ccg 0-0008: ucsi_ccg_init failed - -110
    Jan 26 02:05:36 systemd[1]: systemd-logind.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: systemd-machined.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: avahi-daemon.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: bluetooth.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: ModemManager.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: polkit.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: NetworkManager.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: thermald.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: key-mapper.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 systemd[1]: wpa_supplicant.service: Unexpected error response from GetNameOwner(): Connection terminated
    Jan 26 02:05:36 sddm-helper[1298]: pam_systemd(sddm-greeter:session): Failed to create session: Message recipient disconnected from message bus without replying
    Jan 26 02:05:36 sddm[900]: Failed to read display number from pipe
    Jan 26 02:05:38 sddm[900]: Failed to read display number from pipe
    Jan 26 02:05:40 sddm[900]: Failed to read display number from pipe
    Jan 26 02:05:40 sddm[900]: Could not start Display server on vt 1
    Jan 26 02:06:19 systemd[1]: Failed to start Samba NMB Daemon.
    Jan 26 02:06:19 smbd[2281]: [2021/01/26 02:06:19.347995,  0] ../../lib/util/become_daemon.c:135(daemon_ready)
    Jan 26 02:06:19 smbd[2281]:   daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
    Jan 26 02:06:49 kup-daemon[2794]: kup.daemon: "Kup is not enabled, enable it from the system settings module. You can do that by running kcmshell5 kup"
    Jan 26 02:06:49 bluetoothd[2970]: profiles/audio/avctp.c:avctp_server_socket() setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:49 bluetoothd[2970]: avrcp-controller: Protocol not supported (93)
    Jan 26 02:06:49 bluetoothd[2970]: profiles/audio/avctp.c:avctp_server_socket() setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:49 bluetoothd[2970]: audio-avrcp-target: Protocol not supported (93)
    Jan 26 02:06:49 pulseaudio[2759]: Found duplicated D-Bus path for adapter /org/bluez/hci0
    Jan 26 02:06:49 pulseaudio[2759]: Found duplicated D-Bus path for device /org/bluez/hci0/dev_E8_D0_3C_F4_EF_1F
    Jan 26 02:06:49 pulseaudio[2759]: Found duplicated D-Bus path for device /org/bluez/hci0/dev_E8_D0_3C_AA_F9_75
    Jan 26 02:06:49 pulseaudio[2759]: Found duplicated D-Bus path for device /org/bluez/hci0/dev_4C_4F_EE_26_E1_7A
    Jan 26 02:06:54 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Message Notification: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:54 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Message Access: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:54 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Phone Book Access: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:54 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for File Transfer: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:54 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Object Push: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:06:56 bluetoothd[2970]: src/service.c:btd_service_connect() audio-avrcp-target profile connect failed for 4C:4F:EE:26:E1:7A: Input/output error
    Jan 26 02:06:59 bluetoothd[2970]: src/service.c:btd_service_connect() avrcp-controller profile connect failed for E8:D0:3C:AA:F9:75: Input/output error
    Jan 26 02:07:03 bluetoothd[2970]: src/profile.c:record_cb() Unable to get Headset Voice gateway SDP record: Host is down
    Jan 26 02:08:39 systemd-coredump[5053]: [🡕] Process 2595 (kwin_x11) of user 1001 dumped core.
                                            
                                            Stack trace of thread 2595:
                                            #0  0x00007f9c08e4f615 n/a (n/a + 0x0)
    Jan 26 02:09:04 sddm-helper[5329]: gkr-pam: unable to locate daemon control file
    Jan 26 02:09:05 systemd[5340]: openrazer-daemon.service: Failed at step EXEC spawning /usr/bin/openrazer-daemon: No such file or directory
    Jan 26 02:09:05 systemd[5331]: Failed to start Daemon to manage razer devices in userspace.
    Jan 26 02:09:06 systemd-coredump[5822]: [🡕] Process 5810 (paleofetch) of user 1000 dumped core.
                                            
                                            Stack trace of thread 5810:
                                            #0  0x00007fac71a8c5de __strncpy_avx2 (libc.so.6 + 0x1645de)
                                            #1  0x0000563853966537 n/a (paleofetch + 0x3537)
                                            #2  0x000056385396519f n/a (paleofetch + 0x219f)
                                            #3  0x00007fac71950152 __libc_start_main (libc.so.6 + 0x28152)
                                            #4  0x00005638539653ce n/a (paleofetch + 0x23ce)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Message Notification: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Message Access: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Phone Book Access: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() RFCOMM server failed for Synchronization: rfcomm_bind: Address already in use (98)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for File Transfer: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:09:06 bluetoothd[2970]: src/profile.c:ext_start_servers() L2CAP server failed for Object Push: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
    Jan 26 02:09:07 kup-daemon[5912]: kup.daemon: "Kup is not enabled, enable it from the system settings module. You can do that by running kcmshell5 kup"
    Jan 26 02:09:08 bluetoothd[2970]: src/service.c:btd_service_connect() audio-avrcp-target profile connect failed for 4C:4F:EE:26:E1:7A: Input/output error
    Jan 26 02:09:11 bluetoothd[2970]: src/service.c:btd_service_connect() avrcp-controller profile connect failed for E8:D0:3C:AA:F9:75: Input/output error
    Jan 26 02:09:15 bluetoothd[2970]: src/profile.c:record_cb() Unable to get Headset Voice gateway SDP record: Host is down
    Jan 25 21:09:46 systemd-udevd[8577]: nvme1n1p3: /etc/udev/rules.d/60-ioschedulers.rules:2 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:01.0/0000:04:00.0/nvme/nvme1/nvme1n1/nvme1n1p3/queue/scheduler}, ignoring: No such file or directory
    ╭─svengali at DR460NIZED-3900X in ⌁
    ╰─λ

This seems like the result of the real problem, which I can still can’t figure out.
I also have this type of errors (network online related).
I am on Arch. I tried an downgraded networkmanager (as suspected from an Arch-forum report).
My best case is a long time wait for sddm with a failed NM. I have to start NM twice :frowning_face: in order to get it working properly, which makes me think it maybe DNS/resolve or nss (latest network related update) related.

I have no more ideas.

My concern is I haven’t seen the same report flooding arch-related fora, so it could be a user-mistake/mis-configuration or similar.

We shall see… :thinking:

1 Like

I thought the same, and I saw the report you are referencing about the downgraded NM, which I also tried, with the same results. I am trying the xanmod kernel on the next reboot and and see what happens, and then I'm going to try the newest development kernel 5.10.10....but it's interesting to me that you mention NSS because I THINK, IIRC, that the issue actually started for me when the system did an update to nsswitch- I had a new nsswitch.conf.pacnew that I merged with the existing nsswitch.conf (unfortunately without backing up first) and from there, I think, is where the issue began....I could be mistaken, and I'm going off memory, but I feel like that's when it started. I'm going to try to find an older copy of nsswitch.conf and see if I can revert it to it's old configuration. I remember that the diff didn't have much in the way of changes, only two lines IIRC, so I might be able to remember it and manually change the file.....I'll post my results....

1 Like

May offer some answers:

4 Likes

I don’t think these are relevant to the issue. I still think the same

I have found an incomplete workaround for the network initialization, but not for sddm long delay to show (I am not sure you have the same…).
I have noticed that after login, having no network (no NM-qt icon), I only needed to start NetworkManager-wait-online.service and NM started, connecting successfully.

I edited NetworkManager-wait-online.service and added

[Service]
# Debug failure (added)
Restart=on-failure

# Debug failure (changed)
Environment=NM_ONLINE_TIMEOUT=10
#Environment=NM_ONLINE_TIMEOUT=30

This way I had network after login, but sddm delay was the same. :sob:

My next suspicion is pam , but the error I see just before NM failure is about p2p :face_with_thermometer:

journalctl -u NetworkManager -b-1 --no-hostname --no-pager

... latest part ...
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.2725] device (wlan0): interface index 3 renamed iface from 'wlan0' to 'wlp2s0'
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.2790] device (wlp2s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6199] device (wlp2s0): supplicant interface state: internal-starting -> disconnected
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6201] Wi-Fi P2P device controlled by interface wlp2s0 created
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6205] manager: (p2p-dev-wlp2s0): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkManager/Devices/4)
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6212] device (p2p-dev-wlp2s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6231] device (wlp2s0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
Ιαν 26 19:48:09 NetworkManager[399]: <info>  [1611683289.6250] device (p2p-dev-wlp2s0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Ιαν 26 19:48:09 NetworkManager[399]: <warn>  [1611683289.6282] sup-iface[75c873d7735d7f8d,0,wlp2s0]: call-p2p-cancel: failed with P2P cancel failed
Ιαν 26 19:48:56 systemd[1]: NetworkManager.service: Unexpected error response from GetNameOwner(): Connection terminated
Ιαν 26 19:48:56 NetworkManager[399]: <info>  [1611683336.0926] caught SIGTERM, shutting down normally.
Ιαν 26 19:48:56 NetworkManager[399]: <info>  [1611683336.0951] device (wlp2s0): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
Ιαν 26 19:48:56 NetworkManager[399]: <info>  [1611683336.0983] device (p2p-dev-wlp2s0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Ιαν 26 19:48:56 NetworkManager[399]: <info>  [1611683336.0993] manager: startup complete
Ιαν 26 19:48:56 NetworkManager[399]: <info>  [1611683336.1252] exiting (success)
Ιαν 26 19:48:56 systemd[1]: NetworkManager.service: Succeeded.

@SvengaliExploit please compare with your logs and confirm if they are alike, or mine is a different one.

1 Like

This is everything from boot forward. Now, here's an interesting tidbit. I updated the system using sudo pacman -Syu, rebooted, system totally hung and never booted, this is after about 15 minutes of sitting. It said that Samba NMB failed to start, and sat there hung up never reaching graphic.target.....I had to restore the most recent Timeshift image to boot, which I've done, and here is the output....I'm going to put an strace on dbus.service and see what it turns up on the next reboot. Also, manually starting NetworkManager-wait-online.service immediately started NetworkManager and my internet connection immediately connected.

  ╭─svengali at DR460NIZED-3900X in ⌁
    ╰─λ sudo systemctl start NetworkManager-wait-online.service                                                                                                                                                                                                                                                                                                                                                                           04:27:29
    [sudo] password for svengali:       
    ╭─svengali at DR460NIZED-3900X in ⌁
    ╰─λ journalctl -u NetworkManager -b-1 --no-hostname --no-pager                                                                                                                                                                                                                                                                                                                                                                        23:28:19
    -- Journal begins at Thu 2021-01-07 05:20:58 EST, ends at Wed 2021-01-27 04:28:10 EST. --
    Jan 27 04:08:25 systemd[1]: Starting Network Manager...
    Jan 27 04:08:25 NetworkManager[831]: <info>  [1611738505.9836] NetworkManager (version 1.28.1dev+7+g3f5df3cdc6-1) is starting... (for the first time)
    Jan 27 04:08:25 NetworkManager[831]: <info>  [1611738505.9836] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 20-connectivity.conf)
    Jan 27 04:08:25 systemd[1]: Started Network Manager.
    Jan 27 04:08:25 NetworkManager[831]: <info>  [1611738505.9846] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
    Jan 27 04:08:25 NetworkManager[831]: <info>  [1611738505.9877] manager[0x564d7ac7d030]: monitoring kernel firmware directory '/lib/firmware'.
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0285] hostname: hostname: using hostnamed
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0285] hostname: hostname changed from (none) to "DR460NIZED-3900X"
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0304] dns-mgr[0x564d7ac35220]: init: dns=default,systemd-resolved rc-manager=resolvconf (auto)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0309] rfkill1: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:01.2/0000:02:00.0/0000:03:03.0/0000:05:00.0/ieee80211/phy0/rfkill1) (driver iwlwifi)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0310] manager[0x564d7ac7d030]: rfkill: Wi-Fi hardware radio set enabled
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0310] manager[0x564d7ac7d030]: rfkill: WWAN hardware radio set enabled
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0324] Loaded device plugin: NMAtmManager (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-adsl.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0358] Loaded device plugin: NMBluezManager (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-bluetooth.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0374] Loaded device plugin: NMOvsFactory (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-ovs.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0447] Loaded device plugin: NMTeamFactory (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-team.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0466] Loaded device plugin: NMWifiFactory (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-wifi.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0471] Loaded device plugin: NMWwanFactory (/usr/lib/NetworkManager/1.28.1dev+7+g3f5df3cdc6-1/libnm-device-plugin-wwan.so)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0473] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0474] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0478] manager: Networking is enabled by state file
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0479] dhcp-init: Using DHCP client 'internal'
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0481] settings: Loaded settings plugin: keyfile (internal)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0507] device (lo): carrier: link connected
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0508] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0513] manager: (enp6s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0521] settings: (enp6s0): created default wired connection 'Wired connection 1'
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.0524] device (enp6s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2495] manager: (enp7s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/3)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2502] settings: (enp7s0): created default wired connection 'Wired connection 2'
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2504] device (enp7s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2757] device (wlp5s0): driver supports Access Point (AP) mode
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2759] manager: (wlp5s0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/4)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.2764] device (wlp5s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.4704] device (wlp5s0): set-hw-addr: set MAC address to 02:C3:A2:63:5D:39 (scanning)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.6594] ovsdb: Could not connect: No such file or directory
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.6604] modem-manager: ModemManager available
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7312] device (wlp5s0): supplicant interface state: internal-starting -> disconnected
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7312] Wi-Fi P2P device controlled by interface wlp5s0 created
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7313] manager: (p2p-dev-wlp5s0): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkManager/Devices/5)
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7315] device (p2p-dev-wlp5s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7319] device (wlp5s0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
    Jan 27 04:08:26 NetworkManager[831]: <info>  [1611738506.7322] device (p2p-dev-wlp5s0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
    Jan 27 04:08:26 NetworkManager[831]: <warn>  [1611738506.7344] sup-iface[c7ac645c30fd0fef,0,wlp5s0]: call-p2p-cancel: failed with P2P cancel failed
    Jan 27 04:08:32 NetworkManager[831]: <info>  [1611738512.2755] manager: startup complete
    Jan 27 04:15:17 NetworkManager[831]: <info>  [1611738917.8475] device (wlp5s0): set-hw-addr: set MAC address to 62:E3:9E:A7:49:84 (scanning)
    Jan 27 04:15:17 NetworkManager[831]: <info>  [1611738917.8716] device (wlp5s0): supplicant interface state: disconnected -> inactive
    Jan 27 04:15:17 NetworkManager[831]: <info>  [1611738917.8716] device (p2p-dev-wlp5s0): supplicant management interface state: disconnected -> inactive
    Jan 27 04:22:10 NetworkManager[831]: <info>  [1611739330.7614] device (wlp5s0): set-hw-addr: set MAC address to FE:D2:A3:5E:AC:CB (scanning)
    Jan 27 04:22:10 NetworkManager[831]: <info>  [1611739330.7805] device (wlp5s0): supplicant interface state: inactive -> disconnected
    Jan 27 04:22:10 NetworkManager[831]: <info>  [1611739330.7805] device (p2p-dev-wlp5s0): supplicant management interface state: inactive -> disconnected
    Jan 27 04:22:10 NetworkManager[831]: <info>  [1611739330.7856] device (wlp5s0): supplicant interface state: disconnected -> inactive
    Jan 27 04:22:10 NetworkManager[831]: <info>  [1611739330.7856] device (p2p-dev-wlp5s0): supplicant management interface state: disconnected -> inactive
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0157] modem-manager: ModemManager no longer available
    Jan 27 04:22:25 systemd[1]: Stopping Network Manager...
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0652] caught SIGTERM, shutting down normally.
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0660] device (wlp5s0): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'managed')
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0669] device (wlp5s0): set-hw-addr: reset MAC address to 3C:F0:11:3C:9E:1B (unmanage)
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0694] device (p2p-dev-wlp5s0): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
    Jan 27 04:22:25 NetworkManager[831]: <info>  [1611739345.0702] exiting (success)
    Jan 27 04:22:25 systemd[1]: NetworkManager.service: Succeeded.
    Jan 27 04:22:25 systemd[1]: Stopped Network Manager.
    ╭─svengali at DR460NIZED-3900X in ⌁
    ╰─λ

It seems it should be the same issue with mine.
The suspected villains IMHO are one or a combination of NM, dbus, pam, sddm.

Questions:

sup-iface[c7ac645c30fd0fef,0,wlp5s0]: call-p2p-cancel: failed with P2P cancel failed

  1. Why would P2P make connection attempt to fail, when WiFi is managed?
  2. Why would SDDM greeter wait for a network connection?
Ιαν 27 13:31:03 systemd[1]: Failed to start Network Manager Wait Online.
Ιαν 27 13:31:03 systemd[1]: bluetooth.service: Unexpected error response from GetNameOwner(): Connection terminated
Ιαν 27 13:31:03 systemd[1]: systemd-logind.service: Unexpected error response from GetNameOwner(): Connection terminated
Ιαν 27 13:31:03 systemd[1]: NetworkManager.service: Unexpected error response from GetNameOwner(): Connection terminated
Ιαν 27 13:31:03 systemd[1]: wpa_supplicant.service: Unexpected error response from GetNameOwner(): Connection terminated
Ιαν 27 13:31:03 sddm-helper[676]: pam_systemd(sddm-greeter:session): Failed to create session: Message recipient disconnected from message bus without replying
Ιαν 27 13:31:03 sddm[440]: Failed to read display number from pipe
Ιαν 27 13:31:06 sddm[440]: Failed to read display number from pipe
Ιαν 27 13:31:08 sddm[440]: Failed to read display number from pipe
Ιαν 27 13:31:08 sddm[440]: Could not start Display server on vt 1
Ιαν 27 13:31:17 sddm-helper[966]: gkr-pam: unable to locate daemon control file

  1. What’s this Unexpected error response from GetNameOwner() about?
  2. Is PAM sick? sddm-helper[676]: pam_systemd(sddm-greeter:session): Failed to create session: Message recipient disconnected from message bus without replying, or SDDM needs to send a better request?

I have scanned and browsed several relevant code issues and sources from the above apps and my general idea is… it’s a mess and a headache to me.

Maybe later (when I find some time) I’ll post to Arch forum to investigate.

3 Likes

You could always try switching to connman. Its interface takes a bit of getting used to, but its a good solid manager. It is usually impacted far less than NM with internet breaking bugs.

2 Likes

Post#44 above by @tbg is what I have been using now for many months. ( actually forgot about it )

'## group: files systemd'

This was the only line I had to comment out for things to work again in /etc/nsswitch.conf.

2 Likes

Thanks for reminding me, I had forgotten to try what was suggested.
Actually the proper almost solution is in another comment, which worked out immediately!!!
@SvengaliExploit try it out:

sudo pacman -S dbus-broker
sudo systemctl enable dbus-broker.service
sudo systemctl --global enable dbus-broker.service

and reboot to check. Remove all other workarounds first.

4 Likes

Tried out the above and rebooted twice as whenever I made a change it would work after the first boot as expected but would fail on the second boot.
I can confirm it works after the second boot.
Thanks

3 Likes

I have also read posts stating that setting IPv6 to "ignore" in Network Manager may help with this.

I had IPv6 set to ignore in Network Manager from day one and the problem which is now some what fix started years afterwards. :wink:

Yes, I always disable IPv6 normally myself as well. For those that don't I just thought I'd put it out there as a suggestion as I'd read one comment on the Arch forum that it improved things for them.

1 Like

Only problem for me is that I've got a few things that require IPv6 and UPnP opening a stateless port through my router, so I kind of need IPv6......I had tried the dbus-broker fix, but didn't have any luck the last time, except I'd changed kernels at that point when at last I tried. I'm going to give it a try with the current config and see what happens. I also found my patch file for nsswitch.conf and have reverted it back to it's original state and am going to try that first, before giving dbus-broker another try......Although I feel like, if dbus-broker can fix the issue it's a better solution than using a deprecated nsswitch.conf file, mainly because I'm not sure what the ramifications are of removing the updated lines. Only lines 4, 5, & 10 were changed with the update to nsswitch.....

1 Like

OOOOOOkkkkkk......soooooooo, it's fixed lol I have no idea how or what happened, but it just booted perfectly, and I'm not sure what did the trick.....it was NOT dbus-broker, as it's currently disabled and not running. COULD be the edits to nsswitch.conf- I'm going to revert my reversion (lol) and see if the issue returns. What happened on the PREVIOUS boot is that the system hung where X should have started, but I was able to Ctrl+Alt+F3 to another TTY, and automatically thinking that it was the same issue I went through several things- I enabled and started NetworkManager-wait-online, I also enabled and started nohang.service, but before that I disabled dbus-broker, thinking that IT was the change that was preventing me from reaching graphical.target<-----in fact, the issue was that the grub menu was defaulting to the xanmod kernel, which I suppose for some reason failed to properly add the Nvidia kernel module when it installed, because THAT is what prevented me from getting a normal boot. I rebooted once I noticed that and switched to the zen2 kernel and voila! she booted up perfectly, and practically INSTANTLY (you've gotta love a Sabrent Rocket NVMe PCI-e Gen4 x4 SSD!! WHEW that thing is FAST!), without the slightest bit of hesitation, and when I logged in, low-and-behond everything was working perfectly.....so now I'm going to reboot one more time to see if it holds true a second time and then start figuring out which of those things was the solution.....

except

despite

But, we got there in the end.

indeed we did....and certainly not for lack of effort! Thanks to all you guys for helping out, too!

Glad to hear your issue has been resolved. Some posts on this topic claimed two reboots were necessary for the fix to take. Maybe that's why things started to work all of a sudden. Here's another thing others could test if searching for a solution.

This changes the NetworkManager-wait-online.service default behavior with an override file:

 /etc/systemd/system/NetworkManager-wait-online.service.d/override.conf

Contents:

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

Whenever I had a new kernel or made changes while testing different things it always worked the first boot as expected but would fail the second time taking about 3 or 4 min to boot.
Don't celebrate till you reboot a few times. :shushing_face:

1 Like