dbus timeout-ed during an upgrade, taking services down including gdm
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
D-Bus |
New
|
Unknown
|
|||
systemd |
New
|
Unknown
|
|||
accountsservice (Ubuntu) |
Invalid
|
Undecided
|
Unassigned | ||
Focal |
Invalid
|
Undecided
|
Unassigned | ||
Groovy |
Invalid
|
Undecided
|
Unassigned | ||
Hirsute |
Invalid
|
Undecided
|
Unassigned | ||
Impish |
Invalid
|
Undecided
|
Unassigned | ||
Jammy |
Invalid
|
Undecided
|
Unassigned | ||
dbus (Ubuntu) |
Invalid
|
High
|
Unassigned | ||
Focal |
Invalid
|
High
|
Unassigned | ||
Groovy |
Invalid
|
Undecided
|
Unassigned | ||
Hirsute |
Won't Fix
|
Undecided
|
Unassigned | ||
Impish |
Invalid
|
High
|
Unassigned | ||
Jammy |
Invalid
|
High
|
Unassigned | ||
gnome-shell (Ubuntu) |
Invalid
|
Undecided
|
Unassigned | ||
Focal |
Invalid
|
Undecided
|
Unassigned | ||
Groovy |
Invalid
|
Undecided
|
Unassigned | ||
Hirsute |
Invalid
|
Undecided
|
Unassigned | ||
Impish |
Invalid
|
Undecided
|
Unassigned | ||
Jammy |
Invalid
|
Undecided
|
Unassigned | ||
systemd (Ubuntu) |
Fix Released
|
Undecided
|
Lukas Märdian | ||
Focal |
Fix Released
|
Undecided
|
Unassigned | ||
Impish |
Fix Released
|
Undecided
|
Unassigned | ||
Jammy |
Fix Released
|
Undecided
|
Lukas Märdian |
Bug Description
[Impact]
* There's currently a deadlock between PID 1 and dbus-daemon: in some
cases dbus-daemon will do NSS lookups (which are blocking) at the same
time PID 1 synchronously blocks on some call to dbus-daemon (e.g. `GetConnectionU
that by setting SYSTEMD_
which will disable synchronously blocking varlink calls from nss-systemd
to PID 1.
* This can lead to delayed boot times
* It can also lead to dbus-daemon being killed/re-started, taking down other services with it, like GDM, killing user sessions on the way (e.g. on installing updates)
[Test Plan]
* This bug is really hard to reproduce, as can be seen from the multi-year long discussion at https:/
* Canonical's CPC team has the ability to reproduce this issue (with a relatively high probability) in their Azure test environment, due to the specific setup they are using
* So our test plan is to ask CPC (@gjolly) for confirmation if the issue is fixed.
[Where problems could occur]
* This fix touches the communication between systemd and dbus daemon, especially the NSS lookup, so if something is broken the (user-)name resolution could be broken.
* As a workaround dbus-daemon could be replaced by dbus-broker, which never showed this issue or the behaviour could be changed back by using the `SYSTEMD_
#/etc/systemd/
[Service]
Environment=
[Other Info]
* Fixed upstream (v251) in https:/
=== Original Description ===
This morning I found my computer on the login screen.
But not the one of the screen log, no a new one - so something must have crashed.
Logging in again confirmed that all apps were gone and the gnome shell was brought down what seems like triggered by a background update o accountsservice.
As always things are not perfectly clear :-/
The following goes *back* in time through my logs one by one.
Multiple apps crashed at 06:09, but we will find later that this is a follow on issue of the underlying gnome/X/... recycling.
-rw-r----- 1 paelzer whoopsie 52962868 Apr 8 06:09 _usr_bin_
-rw-r----- 1 paelzer whoopsie 986433 Apr 8 06:09 _usr_lib_
rdkit was failing fast and giving up (that will be a different bug, it just seems broken on my system):
Apr 08 06:10:13 Keschdeichel systemd[1]: Started RealtimeKit Scheduling Policy Service.
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel rtkit-daemon[
Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:10:13 Keschdeichel dbus-daemon[1208]: [system] Activating via systemd: service name='org.
Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:10:13 Keschdeichel systemd[1]: Failed to start RealtimeKit Scheduling Policy Service.
Apr 08 06:10:13 Keschdeichel bluetoothd[
But that already was only triggered by a gnome restart that kicked of earlier:
Apr 08 06:09:27 Keschdeichel systemd[1726656]: Started GNOME Shell on Wayland.
Apr 08 06:09:27 Keschdeichel systemd[1726656]: Reached target GNOME Shell on Wayland.
Apr 08 06:09:27 Keschdeichel systemd[1726656]: Reached target GNOME Session is initialized.
Apr 08 06:09:27 Keschdeichel systemd[1726656]: Reached target GNOME Wayland Session.
Apr 08 06:09:27 Keschdeichel systemd[1726656]: Reached target GNOME Session (session: gnome-login).
X was recycleing before:
Apr 08 06:09:19 Keschdeichel systemd[10683]: Stopping GNOME Shell on X11...
...
Apr 08 06:09:22 Keschdeichel /usr/lib/
Apr 08 06:09:22 Keschdeichel /usr/lib/
It seems like some internal service broke and everything that followed was a secondary issue to that:
Apr 08 06:09:19 Keschdeichel systemd[1]: NetworkManager.
Apr 08 06:09:19 Keschdeichel systemd[1]: wpa_supplicant.
Apr 08 06:09:19 Keschdeichel systemd[1]: thermald.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel thermald[1256]: [WARN]Terminating ...
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Got SIGTERM, quitting.
Apr 08 06:09:19 Keschdeichel systemd[1]: udisks2.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel ModemManager[1308]: <info> Caught signal, shutting down...
Apr 08 06:09:19 Keschdeichel systemd[1]: switcheroo-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface vnet0.IPv6 with address fe80::fc54:
Apr 08 06:09:19 Keschdeichel systemd[1]: accounts-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface strswanbr2.IPv4 with address 192.168.2.0.
Apr 08 06:09:19 Keschdeichel systemd[1]: gdm.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface virbr0.IPv4 with address 192.168.122.1.
Apr 08 06:09:19 Keschdeichel systemd[1]: systemd-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface strswanbr1.IPv4 with address 192.168.1.0.
Apr 08 06:09:19 Keschdeichel systemd[1]: systemd-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface lxdbr0.IPv6 with address fd42:fa18:
Apr 08 06:09:19 Keschdeichel systemd-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface lxdbr0.IPv4 with address 10.253.194.1.
Apr 08 06:09:19 Keschdeichel systemd[1]: switcheroo-
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface wlp4s0.IPv6 with address fe80::6832:
Apr 08 06:09:19 Keschdeichel systemd[1]: systemd-
Apr 08 06:09:19 Keschdeichel bluetoothd[
Apr 08 06:09:19 Keschdeichel systemd[1]: avahi-daemon.
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface wlp4s0.IPv4 with address 10.7.0.42.
Apr 08 06:09:19 Keschdeichel systemd[1]: ModemManager.
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface enp0s31f6.IPv6 with address fe80::80a8:
Apr 08 06:09:19 Keschdeichel systemd[1]: polkit.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface enp0s31f6.IPv4 with address 10.7.0.69.
Apr 08 06:09:19 Keschdeichel systemd[1]: bolt.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface lo.IPv6 with address ::1.
Apr 08 06:09:19 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1.
Apr 08 06:09:19 Keschdeichel systemd[1]: packagekit.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel wpa_supplicant[
Apr 08 06:09:19 Keschdeichel systemd[1]: colord.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel systemd[1]: upower.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel systemd[1]: bluetooth.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel systemd[1]: fwupd.service: Unexpected error response from GetNameOwner(): Connection terminated
Apr 08 06:09:19 Keschdeichel xdg-desktop-
Apr 08 06:09:19 Keschdeichel NetworkManager[
Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: avahi-daemon 0.7 exiting.
Apr 08 06:09:19 Keschdeichel systemd[1]: rtkit-daemon.
Apr 08 06:09:19 Keschdeichel systemd[1]: Starting Process error reports when automatic reporting is enabled...
Apr 08 06:09:19 Keschdeichel systemd[1]: colord.service: Succeeded.
Apr 08 06:09:19 Keschdeichel systemd[10683]: Stopped target GNOME X11 Session (session: ubuntu).
Apr 08 06:09:19 Keschdeichel systemd[10683]: Stopped target Current graphical user session.
Apr 08 06:09:19 Keschdeichel systemd[10683]: unicast-
Apr 08 06:09:19 Keschdeichel systemd[10683]: Stopped Path trigger for Avahi .local domain notifications.
Apr 08 06:09:19 Keschdeichel systemd[10683]: update-
Apr 08 06:09:19 Keschdeichel gnome-shell[11036]: gnome-shell: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
The last things before was systemd reload - maybe due to a background upgrade?
Apr 08 06:08:54 Keschdeichel dbus-daemon[1208]: Unknown group "power" in message bus configuration file
Apr 08 06:08:54 Keschdeichel dbus-daemon[1208]: [system] Reloaded configuration
Apr 08 06:08:54 Keschdeichel dbus-daemon[1208]: Unknown group "power" in message bus configuration file
Apr 08 06:08:54 Keschdeichel dbus-daemon[1208]: [system] Reloaded configuration
Apr 08 06:08:54 Keschdeichel dbus-daemon[1208]: Unknown group "power" in message bus configuration file
Apr 08 06:08:54 Keschdeichel systemd[1]: Reloading.
And indeed there was an upgrade going on:
40773 2020-04-08 06:08:46 status installed libc-bin:amd64 2.31-0ubuntu7
40774 2020-04-08 06:08:54 startup archives unpack
40775 2020-04-08 06:08:54 upgrade accountsservice
40776 2020-04-08 06:08:54 status half-configured accountsservice
40777 2020-04-08 06:08:54 status unpacked accountsservice
40778 2020-04-08 06:08:54 status half-installed accountsservice
40779 2020-04-08 06:08:54 status triggers-pending dbus:amd64 1.12.16-2ubuntu2
40780 2020-04-08 06:09:19 status unpacked accountsservice
40781 2020-04-08 06:09:20 upgrade libaccountsserv
40782 2020-04-08 06:09:20 status triggers-pending libc-bin:amd64 2.31-0ubuntu7
40783 2020-04-08 06:09:20 status half-configured libaccountsserv
40784 2020-04-08 06:09:20 status unpacked libaccountsserv
40785 2020-04-08 06:09:20 status half-installed libaccountsserv
40786 2020-04-08 06:09:20 status unpacked libaccountsserv
Nothing suspicious before that time.
ProblemType: Bug
DistroRelease: Ubuntu 20.04
Package: accountsservice 0.6.55-0ubuntu11
ProcVersionSign
Uname: Linux 5.3.0-45-generic x86_64
NonfreeKernelMo
ApportVersion: 2.20.11-0ubuntu24
Architecture: amd64
CurrentDesktop: ubuntu:GNOME
Date: Wed Apr 8 07:51:03 2020
InstallationDate: Installed on 2018-10-12 (543 days ago)
InstallationMedia: Ubuntu 18.04.1 LTS "Bionic Beaver" - Release amd64 (20180725)
SourcePackage: accountsservice
UpgradeStatus: Upgraded to focal on 2020-04-03 (4 days ago)
Related branches
- Lukas Märdian: Approve
-
Diff: 185 lines (+153/-1)4 files modifieddebian/changelog (+12/-1)
debian/patches/lp1958284-core-move-reset_arguments-to-the-end-of-main-s-finish.patch (+48/-0)
debian/patches/pid1-set-SYSTEMD_NSS_DYNAMIC_BYPASS-1-env-var-for-dbus-da.patch (+91/-0)
debian/patches/series (+2/-0)
- Michael Hudson-Doyle: Approve
-
Diff: 18 lines (+1/-1)2 files modifieddesktop-common (+1/-0)
standard (+0/-1)
tags: | added: rls-ff-incoming |
tags: | added: id-5e988df7fb344884f67bc04f |
Changed in systemd: | |
status: | Unknown → New |
tags: | removed: rls-ff-incoming |
tags: | removed: champagne |
tags: | added: rls-ff-incoming rls-hh-incoming |
tags: | added: rls-ii-incoming |
tags: | added: fr-1460 |
tags: | removed: rls-ff-incoming rls-hh-incoming rls-ii-incoming |
Changed in accountsservice (Ubuntu Groovy): | |
status: | New → Invalid |
Changed in accountsservice (Ubuntu Hirsute): | |
status: | New → Invalid |
Changed in gnome-shell (Ubuntu Groovy): | |
status: | New → Invalid |
Changed in gnome-shell (Ubuntu Hirsute): | |
status: | New → Invalid |
Changed in dbus (Ubuntu Groovy): | |
status: | New → Incomplete |
Changed in dbus (Ubuntu Hirsute): | |
status: | New → Incomplete |
tags: | added: rls-ii-incoming |
no longer affects: | systemd (Ubuntu Groovy) |
no longer affects: | systemd (Ubuntu Hirsute) |
Changed in dbus (Ubuntu Impish): | |
status: | Incomplete → Invalid |
Changed in dbus (Ubuntu Jammy): | |
status: | Incomplete → Invalid |
Changed in dbus (Ubuntu Groovy): | |
status: | Incomplete → Invalid |
Changed in dbus (Ubuntu Focal): | |
status: | Incomplete → Invalid |
description: | updated |
Changed in systemd (Ubuntu Jammy): | |
assignee: | nobody → Lukas Märdian (slyon) |
status: | New → In Progress |
tags: |
added: verification-done verification-done-focal verification-done-impish removed: verification-needed verification-needed-focal verification-needed-impish |
Changed in dbus: | |
status: | Unknown → New |
Most likely this was bug 1843982. So let's use that for now.