[Bug 1896614] Re: Race condition when starting dbus services

[Dan Streetman]

** Description changed:

  [impact]
  
  In certain scenarios, such as high load environments or when "systemctl
  daemon-reload" runs at the same time a dbus service is starting (e.g.
  systemd-logind), systemd is not able to track properly when the service
  has started, keeping the job 'running' forever.
  
  [test case]
  
  set up a 1-cpu VM with Bionic, and configure the system with a ssh key
- so the user can ssh to localhost. Then run:
+ so the user can ssh to localhost. Then run something like:
  
- ubuntu at lp1896614-b:~$ while timeout 5 ssh localhost true; do echo
- 'reloading'; sudo systemctl restart systemd-logind & sudo systemctl
- daemon-reload; done
+ $ while timeout 5 ssh localhost true; do echo 'reloading'; sudo
+ systemctl restart systemd-logind & sudo systemctl daemon-reload; done
  
- that should exit the while loop after only a few attempts. At that
- point, there should be a running job for systemd-logind, and any logins
- attempted after the bug is reproduced should also hang waiting for the
- systemd-logind job to complete, e.g.:
+ if that doesn't work try:
+ 
+ $ while timeout 5 ssh localhost true; do echo 'reloading'; sudo sh -c
+ 'systemctl restart systemd-logind & systemctl daemon-reload'; done
+ 
+ 
+ once the reproducer exits the while loop, there should be a running job for systemd-logind, and any logins attempted after the bug is reproduced should also hang waiting for the systemd-logind job to complete, e.g.:
  
  ubuntu at lp1896614-b:~$ systemctl list-jobs
  JOB UNIT                   TYPE  STATE
  525 systemd-logind.service start running
  669 session-6.scope        start waiting
  664 session-5.scope        start waiting
  
  3 jobs listed.
  
  [regression potential]
  
  any regression would likely involve services that are Type=dbus failing
  to complete starting. as with any systemd change, regressions could also
  involve assertion failures in systemd which causes it to exit.
  
  [scope]
  
  this is needed only for bionic.
  
  this is fixed upstream with commit
  a5a8776ae5e4244b7f5acb2a1bfbe6e0b4d8a870 which is including starting in
  v243, so it is included already in focal and later.
  
  (per upstream bug) this was introduced by upstream commit
  75152a4d6aedbfd3ee8b2d5782b9edf27407622a which was included starting in
  v237, so this bug is not present in xenial or earlier.
  
  [original description]
  
  In certain scenarios, such as high load environments or when "systemctl
  daemon-reload" runs at the same time a dbus service is starting (e.g.
  systemd-logind), systemd is not able to track properly when the service
  has started, keeping the job 'running' forever.
  
  The issue appears when systemd runs the "AddMatch" dbus method call to
  track the service's "NameOwnerChange" once it has already ran. A working
  instance would look like this:
  
  https://pastebin.ubuntu.com/p/868J6WBRQx/
  
  A failing instance would be:
  
  https://pastebin.ubuntu.com/p/HhJZ4p8dT5/
  
  I've been able to reproduce the issue on Bionic (237-3ubuntu10.42)
  running:
  
  sudo systemctl daemon-reload & sudo systemctl restart systemd-logind

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1896614

Title:
  Race condition when starting dbus services

Status in systemd:
  Fix Released
Status in systemd package in Ubuntu:
  Fix Released
Status in systemd source package in Bionic:
  In Progress

Bug description:
  [impact]

  In certain scenarios, such as high load environments or when
  "systemctl daemon-reload" runs at the same time a dbus service is
  starting (e.g. systemd-logind), systemd is not able to track properly
  when the service has started, keeping the job 'running' forever.

  [test case]

  set up a 1-cpu VM with Bionic, and configure the system with a ssh key
  so the user can ssh to localhost. Then run something like:

  $ while timeout 5 ssh localhost true; do echo 'reloading'; sudo
  systemctl restart systemd-logind & sudo systemctl daemon-reload; done

  if that doesn't work try:

  $ while timeout 5 ssh localhost true; do echo 'reloading'; sudo sh -c
  'systemctl restart systemd-logind & systemctl daemon-reload'; done

  
  once the reproducer exits the while loop, there should be a running job for systemd-logind, and any logins attempted after the bug is reproduced should also hang waiting for the systemd-logind job to complete, e.g.:

  ubuntu at lp1896614-b:~$ systemctl list-jobs
  JOB UNIT                   TYPE  STATE
  525 systemd-logind.service start running
  669 session-6.scope        start waiting
  664 session-5.scope        start waiting

  3 jobs listed.

  [regression potential]

  any regression would likely involve services that are Type=dbus
  failing to complete starting. as with any systemd change, regressions
  could also involve assertion failures in systemd which causes it to
  exit.

  [scope]

  this is needed only for bionic.

  this is fixed upstream with commit
  a5a8776ae5e4244b7f5acb2a1bfbe6e0b4d8a870 which is including starting
  in v243, so it is included already in focal and later.

  (per upstream bug) this was introduced by upstream commit
  75152a4d6aedbfd3ee8b2d5782b9edf27407622a which was included starting
  in v237, so this bug is not present in xenial or earlier.

  [original description]

  In certain scenarios, such as high load environments or when
  "systemctl daemon-reload" runs at the same time a dbus service is
  starting (e.g. systemd-logind), systemd is not able to track properly
  when the service has started, keeping the job 'running' forever.

  The issue appears when systemd runs the "AddMatch" dbus method call to
  track the service's "NameOwnerChange" once it has already ran. A
  working instance would look like this:

  https://pastebin.ubuntu.com/p/868J6WBRQx/

  A failing instance would be:

  https://pastebin.ubuntu.com/p/HhJZ4p8dT5/

  I've been able to reproduce the issue on Bionic (237-3ubuntu10.42)
  running:

  sudo systemctl daemon-reload & sudo systemctl restart systemd-logind

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