[Pkg-utopia-maintainers] Bug#867408: upgrade logged me out, stopped network-manager; kernel: dbus-daemon[650]: segfault at 0 ip 0000562c3192e620 sp 00007ffd9c679798 error 6 in dbus-daemon

Thu Jul 6 13:58:35 UTC 2017

Package: dbus
Version: 1.10.20-1
Severity: normal

I ran apt-get dist-upgrade to unstable today from a xfce4-terminal
and at some point in the upgrade the entire X session uncerimoniously
ended, losing anything I was working on at the time and dumping me back
into the lightdm login screen.

When I logged back in, I noticed that network-manager was not running
any longer, and that the apt-get dist-upgrade was still running,
apparently not connected to any terminal. After a while it appeared to
stall out at a conffile prompt.

I killed the dpkg process and ran apt-get -f install, and completed the
upgrade. network-manager remained not running until I manually started
it.

Here's the journal from when network-manager died:

Jul 06 09:16:39 darkstar NetworkManager[21505]: <warn>  [1499346999.1047] bus-manager: disconnected by the system bus
Jul 06 09:16:39 darkstar NetworkManager[21505]: <info>  [1499346999.5461] caught SIGTERM, shutting down normally.

Here's lightdm restarting:

Jul 06 09:16:39 darkstar lightdm[832]: Failed to get D-Bus connection
Jul 06 09:16:39 darkstar systemd[1]: lightdm.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:43 darkstar systemd[1]: lightdm.service: Unit entered failed state.
Jul 06 09:16:43 darkstar systemd[1]: lightdm.service: Triggering OnFailure= dependencies.
Jul 06 09:16:43 darkstar systemd[1]: lightdm.service: Failed with result 'exit-code'.
Jul 06 09:16:43 darkstar systemd[1]: lightdm.service: Service hold-off time over, scheduling restart.
Jul 06 09:16:43 darkstar systemd[1]: Stopped Light Display Manager.
Jul 06 09:16:43 darkstar systemd[1]: Starting Light Display Manager...
Jul 06 09:16:43 darkstar systemd[1]: Started Light Display Manager.

Here's closer to the root cause, where dbus died:

Jul 06 09:16:38 darkstar dbus[650]: [system] Unable to reload configuration: (null)
Jul 06 09:16:38 darkstar dbus-daemon[650]: Unable to reload configuration: (null)
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Main process exited, code=killed, status=11/SEGV
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Unit entered failed state.
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar systemd[1]: Started D-Bus System Message Bus.

Here's the dpkg.log around the same time:

2017-07-06 09:16:37 startup packages configure
2017-07-06 09:16:37 configure libudev1:amd64 233-10 <none>
2017-07-06 09:16:37 status unpacked libudev1:amd64 233-10
2017-07-06 09:16:37 status half-configured libudev1:amd64 233-10
2017-07-06 09:16:37 status installed libudev1:amd64 233-10
2017-07-06 09:16:37 configure libudev1:i386 233-10 <none>
2017-07-06 09:16:37 status unpacked libudev1:i386 233-10
2017-07-06 09:16:38 status half-configured libudev1:i386 233-10
2017-07-06 09:16:38 status installed libudev1:i386 233-10
2017-07-06 09:16:38 startup archives unpack
2017-07-06 09:16:38 upgrade bluez:amd64 5.43-2 5.45-1
2017-07-06 09:16:38 status half-configured bluez:amd64 5.43-2
2017-07-06 09:16:38 status unpacked bluez:amd64 5.43-2
2017-07-06 09:16:38 status half-installed bluez:amd64 5.43-2
2017-07-06 09:16:38 status triggers-pending dbus:amd64 1.10.20-1
2017-07-06 09:16:38 status triggers-pending systemd:amd64 233-9
2017-07-06 09:16:39 status triggers-pending dbus:amd64 1.10.20-1
2017-07-06 09:16:39 status half-installed bluez:amd64 5.43-2
2017-07-06 09:16:39 status unpacked bluez:amd64 5.45-1
2017-07-06 09:16:39 status unpacked bluez:amd64 5.45-1

Here's the whole system journal in the minute in question:

Jul 06 09:16:24 darkstar systemd[1]: Reloading.
Jul 06 09:16:24 darkstar systemd[1]: Configuration file /etc/systemd/system/postfix.service.d/override.conf is marked world-inaccessible. This has no e
Jul 06 09:16:24 darkstar systemd[1]: Configuration file /etc/systemd/system/opendkim.service.d/override.conf is marked world-inaccessible. This has no 
Jul 06 09:16:25 darkstar systemd[1]: Reloading.
Jul 06 09:16:26 darkstar systemd[1]: Configuration file /etc/systemd/system/postfix.service.d/override.conf is marked world-inaccessible. This has no e
Jul 06 09:16:26 darkstar systemd[1]: Configuration file /etc/systemd/system/opendkim.service.d/override.conf is marked world-inaccessible. This has no 
Jul 06 09:16:26 darkstar systemd[1]: Starting Daily apt download activities...
Jul 06 09:16:26 darkstar systemd[1]: Stopped Daily apt upgrade and clean activities.
Jul 06 09:16:26 darkstar systemd[1]: Stopping Daily apt upgrade and clean activities.
Jul 06 09:16:26 darkstar systemd[1]: Started Daily apt upgrade and clean activities.
Jul 06 09:16:26 darkstar systemd[1]: Stopped Daily apt download activities.
Jul 06 09:16:26 darkstar systemd[1]: Stopping Daily apt download activities.
Jul 06 09:16:26 darkstar systemd[1]: Started Daily apt download activities.
Jul 06 09:16:26 darkstar systemd[1]: Started Daily apt download activities.
Jul 06 09:16:38 darkstar dbus[650]: [system] Unable to reload configuration: (null)
Jul 06 09:16:38 darkstar dbus-daemon[650]: Unable to reload configuration: (null)
Jul 06 09:16:39 darkstar kernel: dbus-daemon[650]: segfault at 0 ip 0000562c3192e620 sp 00007ffd9c679798 error 6 in dbus-daemon (deleted)[562c31912000+
Jul 06 09:16:39 darkstar avahi-daemon[648]: Disconnected from D-Bus, exiting.
Jul 06 09:16:39 darkstar bluetoothd[634]: Disconnected from D-Bus. Exiting.
Jul 06 09:16:39 darkstar kernel: wlan0: deauthenticating from 00:a0:bc:67:55:c1 by local choice (Reason: 3=DEAUTH_LEAVING)
Jul 06 09:16:39 darkstar wpa_supplicant[959]: wlan0: CTRL-EVENT-DISCONNECTED bssid=00:a0:bc:67:55:c1 reason=3 locally_generated=1
Jul 06 09:16:39 darkstar wpa_supplicant[959]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Jul 06 09:16:39 darkstar wpa_supplicant[959]: wlan0: CTRL-EVENT-TERMINATING
Jul 06 09:16:39 darkstar systemd[20617]: telepathy-mission-control-5.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:39 darkstar avahi-daemon[648]: Got SIGTERM, quitting.
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: console-kit-daemon[4438]: GLib-CRITICAL: Source ID 1141 was not found when attempting to remove it
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: console-kit-daemon[4438]: GLib-CRITICAL: Source ID 336 was not found when attempting to remove it
Jul 06 09:16:39 darkstar kernel: traps: xfce4-power-man[22073] general protection ip:7f3e83019532 sp:7ffd876cfc90 error:0
Jul 06 09:16:39 darkstar kernel:  in libSM.so.6.0.1[7f3e83017000+7000]
Jul 06 09:16:39 darkstar lightdm[832]: Failed to get D-Bus connection
Jul 06 09:16:39 darkstar systemd[20617]: telepathy-mission-control-5.service: Unit entered failed state.
Jul 06 09:16:39 darkstar avahi-daemon[648]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::dafb:4f91:b057:232d.
Jul 06 09:16:39 darkstar systemd[20617]: telepathy-mission-control-5.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar avahi-daemon[648]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.101.
Jul 06 09:16:39 darkstar NetworkManager[21505]: <warn>  [1499346999.1047] bus-manager: disconnected by the system bus
Jul 06 09:16:39 darkstar avahi-daemon[648]: avahi-daemon 0.6.32 exiting.
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Main process exited, code=killed, status=11/SEGV
Jul 06 09:16:39 darkstar bluetoothd[634]: Endpoint unregistered: sender=:1.45 path=/MediaEndpoint/A2DPSource
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Unit entered failed state.
Jul 06 09:16:39 darkstar bluetoothd[634]: Endpoint unregistered: sender=:1.45 path=/MediaEndpoint/A2DPSink
Jul 06 09:16:39 darkstar systemd[1]: dbus.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: GLib-CRITICAL: Source ID 1141 was not found when attempting to remove it
Jul 06 09:16:39 darkstar systemd[1]: Started D-Bus System Message Bus.
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: GLib-CRITICAL: Source ID 1141 was not found when attempting to remove it
Jul 06 09:16:39 darkstar systemd[1376]: telepathy-mission-control-5.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: GLib-CRITICAL: Source ID 336 was not found when attempting to remove it
Jul 06 09:16:39 darkstar systemd[1376]: telepathy-mission-control-5.service: Unit entered failed state.
Jul 06 09:16:39 darkstar console-kit-daemon[4438]: GLib-CRITICAL: Source ID 336 was not found when attempting to remove it
Jul 06 09:16:39 darkstar systemd[1376]: telepathy-mission-control-5.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar rtkit-daemon[18412]: Exiting cleanly.
Jul 06 09:16:39 darkstar systemd[20158]: telepathy-mission-control-5.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:39 darkstar rtkit-daemon[18412]: Demoting known real-time threads.
Jul 06 09:16:39 darkstar systemd[20158]: telepathy-mission-control-5.service: Unit entered failed state.
Jul 06 09:16:39 darkstar rtkit-daemon[18412]: Demoted 0 threads.
Jul 06 09:16:39 darkstar systemd[20158]: telepathy-mission-control-5.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar rtkit-daemon[18412]: Exiting watchdog thread.
Jul 06 09:16:39 darkstar systemd[21463]: telepathy-mission-control-5.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:39 darkstar rtkit-daemon[18412]: Exiting canary thread.
Jul 06 09:16:39 darkstar systemd[21463]: telepathy-mission-control-5.service: Unit entered failed state.
Jul 06 09:16:39 darkstar bluetoothd[634]: Stopping SDP server
Jul 06 09:16:39 darkstar systemd[21463]: telepathy-mission-control-5.service: Failed with result 'exit-code'.
Jul 06 09:16:39 darkstar bluetoothd[634]: Exit
Jul 06 09:16:39 darkstar systemd[1]: lightdm.service: Main process exited, code=exited, status=1/FAILURE
Jul 06 09:16:39 darkstar dbus[1320]: [system] Activating systemd to hand-off: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.ser
Jul 06 09:16:39 darkstar systemd[1]: Reloading.
Jul 06 09:16:39 darkstar dbus[1320]: [system] Successfully activated service 'org.freedesktop.systemd1'
Jul 06 09:16:39 darkstar NetworkManager[21505]: <info>  [1499346999.5461] caught SIGTERM, shutting down normally.
Jul 06 09:16:39 darkstar lightdm[21896]: pam_unix(lightdm:session): session closed for user joey
Jul 06 09:16:39 darkstar NetworkManager[21505]: <info>  [1499346999.5471] device (wlan0): state change: activated -> deactivating (reason 'unmanaged') 

Looks like an upgrade of something, perhaps bluez caused the dbus
trigger to run, and the reload failed for whatever reason,
apparently somehow involving a null pointer dereference by dbus,
segfaulting it and hosing the system.

-- Package-specific info:

-- System Information:
Debian Release: buster/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (500, 'testing'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.9.0-3-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.utf8, LC_CTYPE=en_US.utf8 (charmap=UTF-8), LANGUAGE=en_US.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

-- 
see shy jo
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL: <http://lists.alioth.debian.org/pipermail/pkg-utopia-maintainers/attachments/20170706/0806fb62/attachment.sig>