← Back to team overview

dx-packages team mailing list archive

  1. dx-packages team
  2. Mailing list archive
  3. Message #43596

[Bug 1871538] Re: dbus timeout-ed during an upgrade, taking services down including gdm

  Thread Previous • Date Previous • • Thread Next 
An interesting observation I made is that all journal logs (in this LP
bug and the upstream systemd bug) show the "polkit.service: Unexpected
error response from GetNameOwner(): Connection terminated" message, in
addition to a bunch of other "Connection terminated" errors from
changing services across the different installations
(NetworkManager.service, accounts-daemon.service, systemd-
logind.service, ...). I've also seen logs (from Gauthier) where only
polkit.service is failing.

The polkit.service "Unexpected error response from GetNameOwner()"
message is a log from systemd effectively telling us that systemd cannot
reach org.freedesktop.PolicyKit1 on DBus. But the root cause for that
must be that polkitd is not running (or dbus is somehow stuck in a
deadlock, not responding anymore). This gives a new twist to this issue,
as we might be searching for a phantom in (lib-)systemd... PolicyKit is
using glib's gdbus implementation.

-- 
You received this bug notification because you are a member of DX
Packages, which is subscribed to accountsservice in Ubuntu.
Matching subscriptions: dx-packages
https://bugs.launchpad.net/bugs/1871538

Title:
  dbus timeout-ed during an upgrade, taking services down including gdm

Status in D-Bus:
  Unknown
Status in systemd:
  New
Status in accountsservice package in Ubuntu:
  Invalid
Status in dbus package in Ubuntu:
  Incomplete
Status in gnome-shell package in Ubuntu:
  Invalid
Status in accountsservice source package in Focal:
  Invalid
Status in dbus source package in Focal:
  Incomplete
Status in gnome-shell source package in Focal:
  Invalid
Status in accountsservice source package in Groovy:
  Invalid
Status in dbus source package in Groovy:
  Incomplete
Status in gnome-shell source package in Groovy:
  Invalid
Status in accountsservice source package in Hirsute:
  Invalid
Status in dbus source package in Hirsute:
  Incomplete
Status in gnome-shell source package in Hirsute:
  Invalid
Status in accountsservice source package in Impish:
  Invalid
Status in dbus source package in Impish:
  Incomplete
Status in gnome-shell source package in Impish:
  Invalid

Bug 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_konversation.1000.crash
  -rw-r-----  1 paelzer  whoopsie   986433 Apr  8 06:09 _usr_lib_x86_64-linux-gnu_libexec_drkonqi.1000.crash

  
  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[1729333]: Successfully called chroot.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Successfully dropped privileges.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Successfully limited resources.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: pthread_create failed: Resource temporarily unavailable
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Canary thread running.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Exiting canary thread.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Demoting known real-time threads.
  Apr 08 06:10:13 Keschdeichel rtkit-daemon[1729333]: Demoted 0 threads.
  Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.service: Main process exited, code=exited, status=1/FAILURE
  Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.service: Failed with result 'exit-code'.
  Apr 08 06:10:13 Keschdeichel dbus-daemon[1208]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.1176' (uid=121 pid=>
  Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.service: Start request repeated too quickly.
  Apr 08 06:10:13 Keschdeichel systemd[1]: rtkit-daemon.service: Failed with result 'exit-code'.
  Apr 08 06:10:13 Keschdeichel systemd[1]: Failed to start RealtimeKit Scheduling Policy Service.
  Apr 08 06:10:13 Keschdeichel bluetoothd[1729331]: Bluetooth daemon 5.53

  
  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/gdm3/gdm-x-session[10710]: (EE) systemd-logind: ReleaseControl failed: Unknown object '/org/freedesktop/login1/session/_32'.
  Apr 08 06:09:22 Keschdeichel /usr/lib/gdm3/gdm-x-session[10710]: (II) Server terminated successfully (0). Closing log file.

  
  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.service: Unexpected error response from GetNameOwner(): Connection terminated
  Apr 08 06:09:19 Keschdeichel systemd[1]: wpa_supplicant.service: Unexpected error response from GetNameOwner(): Connection terminated
  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-control.service: Unexpected error response from GetNameOwner(): Connection terminated
  Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface vnet0.IPv6 with address fe80::fc54:ff:fe78:26c2.
  Apr 08 06:09:19 Keschdeichel systemd[1]: accounts-daemon.service: Unexpected error response from GetNameOwner(): Connection terminated
  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-logind.service: Unexpected error response from GetNameOwner(): Connection terminated
  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-machined.service: Unexpected error response from GetNameOwner(): Connection terminated
  Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface lxdbr0.IPv6 with address fd42:fa18:c923:35d5::1.
  Apr 08 06:09:19 Keschdeichel systemd-machined[1255]: Failed to drop reference to machine scope, ignoring: Transport endpoint is not connected
  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-control.service: Succeeded.
  Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface wlp4s0.IPv6 with address fe80::6832:c873:a074:2c7b.
  Apr 08 06:09:19 Keschdeichel systemd[1]: systemd-machined.service: Succeeded.
  Apr 08 06:09:19 Keschdeichel bluetoothd[1724347]: Terminating
  Apr 08 06:09:19 Keschdeichel systemd[1]: avahi-daemon.service: Unexpected error response from GetNameOwner(): Connection terminated
  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.service: Unexpected error response from GetNameOwner(): Connection terminated
  Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: Leaving mDNS multicast group on interface enp0s31f6.IPv6 with address fe80::80a8:743:6b37:e561.
  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.service: Unexpected error response from GetNameOwner(): Connection terminated
  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[1265]: nl80211: deinit ifname=p2p-dev-wlp4s0 disabled_11b_rates=0
  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-por[11011]: xdg-desktop-portal-gtk: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.
  Apr 08 06:09:19 Keschdeichel NetworkManager[1209]: <info>  [1586318959.7797] caught SIGTERM, shutting down normally.
  Apr 08 06:09:19 Keschdeichel avahi-daemon[1204]: avahi-daemon 0.7 exiting.
  Apr 08 06:09:19 Keschdeichel systemd[1]: rtkit-daemon.service: Succeeded.
  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-local-avahi.path: Succeeded.
  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-notifier-release.path: Succeeded.
  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:amd64 0.6.55-0ubuntu10 0.6.55-0ubuntu11
  40776 2020-04-08 06:08:54 status half-configured accountsservice:amd64 0.6.55-0ubuntu10
  40777 2020-04-08 06:08:54 status unpacked accountsservice:amd64 0.6.55-0ubuntu10       
  40778 2020-04-08 06:08:54 status half-installed accountsservice:amd64 0.6.55-0ubuntu10 
  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:amd64 0.6.55-0ubuntu11       
  40781 2020-04-08 06:09:20 upgrade libaccountsservice0:amd64 0.6.55-0ubuntu10 0.6.55-0ubuntu11
  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 libaccountsservice0:amd64 0.6.55-0ubuntu10
  40784 2020-04-08 06:09:20 status unpacked libaccountsservice0:amd64 0.6.55-0ubuntu10   
  40785 2020-04-08 06:09:20 status half-installed libaccountsservice0:amd64 0.6.55-0ubuntu10
  40786 2020-04-08 06:09:20 status unpacked libaccountsservice0:amd64 0.6.55-0ubuntu11

  Nothing suspicious before that time.

  ProblemType: Bug
  DistroRelease: Ubuntu 20.04
  Package: accountsservice 0.6.55-0ubuntu11
  ProcVersionSignature: Ubuntu 5.3.0-45.37~18.04.1-generic 5.3.18
  Uname: Linux 5.3.0-45-generic x86_64
  NonfreeKernelModules: zfs zunicode zavl icp zcommon znvpair
  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)

To manage notifications about this bug go to:
https://bugs.launchpad.net/dbus/+bug/1871538/+subscriptions

References

  Thread Previous • Date Previous • • Thread Next