bug#56519: Shepherd non-deterministically fails to load the "guix-daemon" service after the "user-processes" service has been started

[Ludovic Courtès]

Hi Markus,

>From the /var/log/messages excerpt you sent, it would seem that the root
cause is failing to device mapping for the “streetkid” storage:

Markus Nilsson <markusnilsson890@gmail.com> skribis:

> Jul  1 21:39:35 localhost vmunix: [   16.150396] sd 6:0:1:0: Attached scsi 
> generic sg6 type 0
> Jul  1 21:39:35 localhost vmunix: [   16.157673] sd 6:0:0:0: [sdf] 625142448 
> 512-byte logical blocks: (320 GB/298 GiB)
> Jul  1 21:39:35 localhost vmunix: [   16.157689] sd 6:0:0:0: [sdf] 4096-byte 
> physical blocks
> Jul  1 21:39:35 localhost vmunix: [   16.195016] shepherd[1]: Service 
> device-mapping-streetkid_VG_storage-streetkid_LV_home could not be started.
> Jul  1 21:39:35 localhost vmunix: [   16.197048] shepherd[1]: Service 
> file-system-/home depends on 
> device-mapping-streetkid_VG_storage-streetkid_LV_home.
> Jul  1 21:39:35 localhost vmunix: [   16.199307] shepherd[1]: Service 
> file-system-/home could not be started.
> Jul  1 21:39:35 localhost vmunix: [   16.203577] shepherd[1]: Service 
> file-system-/dev/pts has been started.
> Jul  1 21:39:35 localhost vmunix: [   16.206789] shepherd[1]: Service 
> file-system-/sys/kernel/debug has been started.
> Jul  1 21:39:35 localhost vmunix: [   16.209950] shepherd[1]: Service 
> file-system-/dev/shm has been started.
> Jul  1 21:39:35 localhost vmunix: [   16.212595] shepherd[1]: Service 
> file-system-/sys/firmware/efi/efivars has been started.
> Jul  1 21:39:35 localhost vmunix: [   16.215719] shepherd[1]: Service 
> file-system-/gnu/store has been started.

[...]

> Jul  1 21:39:35 localhost vmunix: [   17.481611] shepherd[1]: Service nscd 
> could not be started.
> Jul  1 21:39:35 localhost vmunix: [   17.499327] ppdev: user-space parallel 
> port driver
> Jul  1 21:39:35 localhost vmunix: [   17.691044]  sdi: sdi1
> Jul  1 21:39:35 localhost vmunix: [   17.949918] sd 6:0:3:0: [sdi] Attached 
> SCSI disk
> Jul  1 21:39:35 localhost vmunix: [   17.956933] shepherd[1]: Service 
> device-mapping-streetkid_VG_storage-streetkid_LV_home could not be started.
> Jul  1 21:39:35 localhost vmunix: [   17.958868] shepherd[1]: Service 
> file-system-/home depends on 
> device-mapping-streetkid_VG_storage-streetkid_LV_home.
> Jul  1 21:39:35 localhost vmunix: [   17.960699] shepherd[1]: Service 
> file-system-/home could not be started.
> Jul  1 21:39:35 localhost vmunix: [   17.962778] shepherd[1]: Service 
> file-systems depends on file-system-/home.
> Jul  1 21:39:35 localhost vmunix: [   17.964868] shepherd[1]: Service 
> file-systems could not be started.
> Jul  1 21:39:35 localhost vmunix: [   17.966751] shepherd[1]: Service 
> user-processes depends on file-systems.
> Jul  1 21:39:35 localhost vmunix: [   17.968643] shepherd[1]: Service 
> user-processes could not be started.
> Jul  1 21:39:35 localhost vmunix: [   17.970712] shepherd[1]: Service 
> guix-daemon depends on user-processes.
> Jul  1 21:39:35 localhost vmunix: [   17.971359] shepherd[1]: Service 
> guix-daemon could not be started.

That is: ‘device-mapping-streetkid_VG_storage-streetkid_LV_home’ fails
to start; shepherd tries to start other services, but they depend on it
so every time it fails with “Service X depends on
device-mapping-streetkid_VG_storage-streetkid_LV_home” followed by
“Service X could not be started”.  Eventually, that propagates down to
‘user-processes’ and ‘guix-daemon’, both of which can’t be started.

You can see the dependency graph of Shepherd services with:

  guix system shepherd-graph …/config.scm | xdot -

So it might not be a Shepherd or Guix issue per se, but rather something
related to that “streetkid” device.  I couldn’t find hints in the log
though.

Ideas?

Thanks,
Ludo’.