Every other reboot I have no networking and a lot of "Unexpected error response from GetNameOwner()"

sender · 24 May 2020 15:43

Hi,

I'm quite puzzled by this one and I wonder if someone can give me a pointer on how to debug this.

It happens almost on 1 in 2 reboots. Boot seems fine until SDDM flickers (crashes). After that, it's possible to log in, only there is no networking at all (WLAN, Bluetooth, WWAN). Contents of the error logs right after login:

λ journalctl -b -p3
-- Logs begin at Mon 2020-05-11 23:35:36 CEST, end at Sun 2020-05-24 13:18:03 CEST. --
mei 24 13:10:14 t480s systemd[1]: Failed to start Network Manager Wait Online.
mei 24 13:10:14 t480s systemd[1]: NetworkManager.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: avahi-daemon.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: bluetooth.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: polkit.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: systemd-logind.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: ModemManager.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s systemd[1]: wpa_supplicant.service: Unexpected error response from GetNameOwner(): Connection terminated
mei 24 13:10:14 t480s sddm-helper[1206]: pam_systemd(sddm-greeter:session): Failed to create session: Message recipient disconnected from message bus without replying
mei 24 13:10:15 t480s systemd-logind[1297]: User of session c1 not known.
mei 24 13:10:18 t480s sddm[769]: Failed to read display number from pipe
mei 24 13:10:18 t480s sddm[769]: Display server failed to start. Exiting
mei 24 13:10:18 t480s sddm-greeter[1269]: Socket error:  "QLocalSocket: Remote closed"
mei 24 13:10:18 t480s systemd-coredump[1414]: Process 769 (sddm) of user 0 dumped core.
                                              
                                              Stack trace of thread 769:
                                              #0  0x00007f42d2319ce5 raise (libc.so.6 + 0x3bce5)
                                              #1  0x00007f42d2303857 abort (libc.so.6 + 0x25857)
                                              #2  0x00007f42d2737938 _ZNK14QMessageLogger5fatalEPKcz (libQt5Core.so.5 + 0x8e938)
                                              #3  0x0000558c91c9afff n/a (sddm + 0x28fff)
                                              #4  0x0000558c91cdf4df _ZN4SDDM4Seat13createDisplayEi (sddm + 0x6d4df)
                                              #5  0x0000558c91cdf6f1 _ZN4SDDM4SeatC2ERK7QStringP7QObject (sddm + 0x6d6f1)
                                              #6  0x0000558c91ce1451 _ZN4SDDM11SeatManager10createSeatERK7QString (sddm + 0x6f451)
                                              #7  0x0000558c91ce22b3 n/a (sddm + 0x702b3)
                                              #8  0x00007f42d2983cde n/a (libQt5Core.so.5 + 0x2dacde)
                                              #9  0x0000558c91ce04f0 _ZN4SDDM10LogindSeat19canGraphicalChangedEb (sddm + 0x6e4f0)
                                              #10 0x0000558c91ce07ff n/a (sddm + 0x6e7ff)
                                              #11 0x00007f42d2983cde n/a (libQt5Core.so.5 + 0x2dacde)
                                              #12 0x00007f42d3346de0 _ZN23QDBusPendingCallWatcher8finishedEPS_ (libQt5DBus.so.5 + 0x79de0)
                                              #13 0x00007f42d3346ee1 n/a (libQt5DBus.so.5 + 0x79ee1)
                                              #14 0x00007f42d297bada _ZN7QObject5eventEP6QEvent (libQt5Core.so.5 + 0x2d2ada)
                                              #15 0x00007f42d294e4d0 _ZN16QCoreApplication15notifyInternal2EP7QObjectP6QEvent (libQt5Core.so.5 + 0x2a54d0)
                                              #16 0x00007f42d2950d56 _ZN23QCoreApplicationPrivate16sendPostedEventsEP7QObjectiP11QThreadData (libQt5Core.so.5 + 0x2a7d56)
                                              #17 0x00007f42d29a7244 n/a (libQt5Core.so.5 + 0x2fe244)
                                              #18 0x00007f42d14ee6be g_main_context_dispatch (libglib-2.0.so.0 + 0x6b6be)
                                              #19 0x00007f42d14f0531 n/a (libglib-2.0.so.0 + 0x6d531)
                                              #20 0x00007f42d14f0571 g_main_context_iteration (libglib-2.0.so.0 + 0x6d571)
                                              #21 0x00007f42d29a6890 _ZN20QEventDispatcherGlib13processEventsE6QFlagsIN10QEventLoop17ProcessEventsFlagEE (libQt5Core.so.5 + 0x2fd890)
                                              #22 0x00007f42d294d05c _ZN10QEventLoop4execE6QFlagsINS_17ProcessEventsFlagEE (libQt5Core.so.5 + 0x2a405c)
                                              #23 0x00007f42d2955066 _ZN16QCoreApplication4execEv (libQt5Core.so.5 + 0x2ac066)
                                              #24 0x0000558c91c9e7e1 main (sddm + 0x2c7e1)
                                              #25 0x00007f42d2305023 __libc_start_main (libc.so.6 + 0x27023)
                                              #26 0x0000558c91c9eaee _start (sddm + 0x2caee)
                                              
                                              Stack trace of thread 820:
                                              #0  0x00007f42d23d2abf __poll (libc.so.6 + 0xf4abf)
                                              #1  0x00007f42d14f04a0 n/a (libglib-2.0.so.0 + 0x6d4a0)
                                              #2  0x00007f42d14f0571 g_main_context_iteration (libglib-2.0.so.0 + 0x6d571)
                                              #3  0x00007f42d29a6890 _ZN20QEventDispatcherGlib13processEventsE6QFlagsIN10QEventLoop17ProcessEventsFlagEE (libQt5Core.so.5 + 0x2fd890)
                                              #4  0x00007f42d294d05c _ZN10QEventLoop4execE6QFlagsINS_17ProcessEventsFlagEE (libQt5Core.so.5 + 0x2a405c)
                                              #5  0x00007f42d2771c62 _ZN7QThread4execEv (libQt5Core.so.5 + 0xc8c62)
                                              #6  0x00007f42d32e2b28 n/a (libQt5DBus.so.5 + 0x15b28)
                                              #7  0x00007f42d2772dd6 n/a (libQt5Core.so.5 + 0xc9dd6)
                                              #8  0x00007f42d22c546f start_thread (libpthread.so.0 + 0x946f)
                                              #9  0x00007f42d23dd3d3 __clone (libc.so.6 + 0xff3d3)
mei 24 13:10:20 t480s systemd-logind[1297]: Failed to start session scope session-c1.scope: Unit session-c1.scope already exists.
mei 24 13:10:20 t480s sddm-helper[1451]: pam_systemd(sddm-greeter:session): Failed to create session: Unit session-c1.scope already exists.
mei 24 13:13:33 t480s bluetoothd[1272]: RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)
mei 24 13:13:33 t480s bluetoothd[1272]: RFCOMM server failed for :1.152/Profile/HSPHS/00001108-0000-1000-8000-00805F9B34FB: rfcomm_bind: Address already in use (98)

After rebooting once (or twice), everything is nice and dandy and the logs are silent of all of this.

λ inxi -Fxxxz -c0
System:    Host: t480s Kernel: 5.6.12-1-MANJARO x86_64 bits: 64 compiler: gcc v: 9.3.0 Desktop: KDE Plasma 5.18.5 
           tk: Qt 5.14.2 wm: kwin_x11 dm: SDDM Distro: Manjaro Linux 
Machine:   Type: Laptop System: LENOVO product: 20L7CTO1WW v: ThinkPad T480s serial: <filter> Chassis: type: 10 
           serial: <filter> 
           Mobo: LENOVO model: 20L7CTO1WW v: SDK0J40697 WIN serial: <filter> UEFI: LENOVO v: N22ET62W (1.39 ) date: 02/18/2020 
Battery:   ID-1: BAT0 charge: 35.9 Wh condition: 46.3/57.0 Wh (81%) volts: 12.4/11.6 model: LGC 01AV478 type: Li-poly 
           serial: <filter> status: Unknown cycles: 266 
           Device-1: hidpp_battery_0 model: Logitech Wireless Mouse MX Anywhere 2 serial: <filter> 
           charge: 55% (should be ignored) rechargeable: yes status: Discharging 
CPU:       Topology: Quad Core model: Intel Core i7-8550U bits: 64 type: MT MCP arch: Kaby Lake rev: A L2 cache: 8192 KiB 
           flags: avx avx2 lm nx pae sse sse2 sse3 sse4_1 sse4_2 ssse3 vmx bogomips: 32012 
           Speed: 800 MHz min/max: 400/4000 MHz Core speeds (MHz): 1: 800 2: 800 3: 800 4: 800 5: 800 6: 800 7: 800 8: 800 
Graphics:  Device-1: Intel UHD Graphics 620 vendor: Lenovo driver: i915 v: kernel bus ID: 00:02.0 chip ID: 8086:5917 
           Display: x11 server: X.Org 1.20.8 driver: intel unloaded: modesetting alternate: fbdev,vesa compositor: kwin_x11 
           resolution: 2560x1440~60Hz 
           OpenGL: renderer: Mesa Intel UHD Graphics 620 (KBL GT2) v: 4.6 Mesa 20.0.6 direct render: Yes 
Audio:     Device-1: Intel Sunrise Point-LP HD Audio vendor: Lenovo driver: snd_hda_intel v: kernel bus ID: 00:1f.3 
           chip ID: 8086:9d71 
           Sound Server: ALSA v: k5.6.12-1-MANJARO 
Network:   Device-1: Intel Ethernet I219-V vendor: Lenovo driver: e1000e v: 3.2.6-k port: efa0 bus ID: 00:1f.6 
           chip ID: 8086:15d8 
           IF: enp0s31f6 state: down mac: <filter> 
           Device-2: Intel Wireless 8265 / 8275 driver: iwlwifi v: kernel port: efa0 bus ID: 3d:00.0 chip ID: 8086:24fd 
           IF: wlp61s0 state: up mac: <filter> 
           IF-ID-1: wwp0s20f0u6 state: down mac: <filter> 
Drives:    Local Storage: total: 953.87 GiB used: 380.07 GiB (39.8%) 
           ID-1: /dev/nvme0n1 vendor: Samsung model: MZVLB1T0HALR-000L7 size: 953.87 GiB speed: 31.6 Gb/s lanes: 4 
           serial: <filter> rev: 5L2QEXA7 scheme: GPT 
Partition: ID-1: / size: 143.19 GiB used: 113.02 GiB (78.9%) fs: ext4 dev: /dev/nvme0n1p5 
Sensors:   System Temperatures: cpu: 49.0 C mobo: N/A 
           Fan Speeds (RPM): cpu: 0 
Info:      Processes: 309 Uptime: 3h 16m Memory: 39.09 GiB used: 6.53 GiB (16.7%) Init: systemd v: 245 Compilers: gcc: 9.3.0 
           clang: 10.0.0 Shell: bash v: 5.0.16 running in: server inxi: 3.0.37

Thanks in advance!

Whinery · 10 June 2020 00:21

Was getting the exact same error and starting using this as a work around for now. Still looking into the error.

I edit the /etc/nsswitch.conf file and then was able to boot again in 7 seconds. Better than 1 min.

# Name Service Switch configuration file.
# See nsswitch.conf(5) for details.

## passwd: files mymachines systemd
## group: files mymachines systemd
shadow: files

publickey: files

hosts: files mymachines myhostname resolve [!UNAVAIL=return] dns
networks: files

protocols: files
services: files
ethers: files
rpc: files

netgroup: files

as you can see I edited out passwd and group with ## so I can easily remove when the bug gets fixed.

sender · 10 June 2020 09:00

What kernel are you using? I'm now testing with 5.7.0-3-MANJARO and no errors until now.

Whinery · 10 June 2020 12:35

I'm using Archlinux and it's happening to me on lts and the latest kernels. I'm not sure if it's dbus or systemd causing the error as both have been updated. Been on the road a lot lately so only had time to google the problem.

Termy · 6 July 2020 14:47

did you find anything yet?
I'm using your workaround, too and found out that it causes Polkit issues (kate can't use poltik anymore for example)

edit: it seems with dbus-broker the issue with boottime/nm is gone, but kate/polkit still persists

Whinery · 6 July 2020 15:51

Will try to boot normal later today, so far no issues at all but was able to enable passwd again. Only have group ## out.

Termy · 6 July 2020 20:08

interesting, i can confirm that only removing systemd from group solves the boot time issue - but sadly polkit/kate still won't work

Whinery · 7 July 2020 03:18

Tried without the group # out and the problem returns after the first boot. Just never had the time to look more into it and can't find any new post on the matter at this time.

sender · 7 July 2020 07:38

For what it's worth: I'm still on 5.7.0-3-MANJARO and didn't edit /etc/nsswitch.conf, and haven't seen the error since.

Termy · 9 July 2020 16:48

for todays update i reverted my system to a working state with timeshift (10.6.2020) and updated from there - unfortunately the issue came back, so definitely not a configuration issue.

sender · 9 July 2020 17:04

haven't seen the error since

I spoke too soon

Today I had a freeze (again): KDE lockscreen, mouse cursor works, no way to log in, restarting plasmashell and/or kwin does not work.

After a reboot via a tty I experienced this issue again. A reboot later: no issue.

Termy · 3 August 2020 08:53

good news, there is a better workaround than the nsswitch.conf thing that breaks polkit for me: disable org.cups.cupsd.service and use socket instead!

systemctl disable org.cups.cupsd.service
systemctl enable org.cups.cupsd.socket

See https://github.com/systemd/systemd/issues/15316#issuecomment-667658293