3

In the partial log below, those dev-disk and dev-dm lines with timed out and timeout, how can I find out which service(eg. that.service) is responsible for them, so that I can for example append an After=that.service in my qubes-core.service (seen below as Qubes Dom0 startup setup) to ensure it is stopped first ?

[ 3866.707545] systemd[1]: Started Show Plymouth Reboot Screen.
[ 3866.777998] qmemman.systemstate[1620]: mem-set domain 3 to 4194304000
[ 3866.778860] qmemman.systemstate[1620]: mem-set domain 7 to 4194304000
[ 3866.779587] qmemman.systemstate[1620]: mem-set domain 6 to 4194304000
[ 3866.951011] systemd[1]: Stopped Restore /run/initramfs on shutdown.
[ 3871.685359] systemd[1]: Received SIGRTMIN+20 from PID 9952 (plymouthd).
[ 3956.361763] systemd[1]: dev-disk-by\x2did-dm\x2dname\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device: Job dev-disk-by\x2did-dm\x2dname\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device/stop timed out.
[ 3956.362322] systemd[1]: Timed out stopping /dev/disk/by-id/dm-name-luks-9ed952b5-2aa8-4564-b700-fb23f5c9e94b.
[ 3956.362945] systemd[1]: dev-disk-by\x2did-dm\x2dname\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device: Job dev-disk-by\x2did-dm\x2dname\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device/stop failed with result 'timeout'.
[ 3956.363698] systemd[1]: dev-disk-by\x2did-lvm\x2dpv\x2duuid\x2dpxC3ch\x2d0MF0\x2dOzJs\x2dJogd\x2d9rOz\x2dJkSt\x2dCf8G7m.device: Job dev-disk-by\x2did-lvm\x2dpv\x2duuid\x2dpxC3ch\x2d0MF0\x2dOzJs\x2dJogd\x2d9rOz\x2dJkSt\x2dCf8G7m.device/stop timed out.
[ 3956.363702] systemd[1]: Timed out stopping /dev/disk/by-id/lvm-pv-uuid-pxC3ch-0MF0-OzJs-Jogd-9rOz-JkSt-Cf8G7m.
[ 3956.366332] systemd[1]: dev-disk-by\x2did-lvm\x2dpv\x2duuid\x2dpxC3ch\x2d0MF0\x2dOzJs\x2dJogd\x2d9rOz\x2dJkSt\x2dCf8G7m.device: Job dev-disk-by\x2did-lvm\x2dpv\x2duuid\x2dpxC3ch\x2d0MF0\x2dOzJs\x2dJogd\x2d9rOz\x2dJkSt\x2dCf8G7m.device/stop failed with result 'timeout'.
[ 3956.367093] systemd[1]: dev-disk-by\x2did-dm\x2duuid\x2dCRYPT\x2dLUKS1\x2d9ed952b52aa84564b700fb23f5c9e94b\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device: Job dev-disk-by\x2did-dm\x2duuid\x2dCRYPT\x2dLUKS1\x2d9ed952b52aa84564b700fb23f5c9e94b\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device/stop timed out.
[ 3956.367098] systemd[1]: Timed out stopping /dev/disk/by-id/dm-uuid-CRYPT-LUKS1-9ed952b52aa84564b700fb23f5c9e94b-luks-9ed952b5-2aa8-4564-b700-fb23f5c9e94b.
[ 3956.368768] systemd[1]: dev-disk-by\x2did-dm\x2duuid\x2dCRYPT\x2dLUKS1\x2d9ed952b52aa84564b700fb23f5c9e94b\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device: Job dev-disk-by\x2did-dm\x2duuid\x2dCRYPT\x2dLUKS1\x2d9ed952b52aa84564b700fb23f5c9e94b\x2dluks\x2d9ed952b5\x2d2aa8\x2d4564\x2db700\x2dfb23f5c9e94b.device/stop failed with result 'timeout'.
[ 3956.368789] systemd[1]: dev-dm\x2d0.device: Job dev-dm\x2d0.device/stop timed out.
[ 3956.368808] systemd[1]: Timed out stopping /dev/dm-0.
[ 3956.372748] systemd[1]: dev-dm\x2d0.device: Job dev-dm\x2d0.device/stop failed with result 'timeout'.
[ 3956.372769] systemd[1]: sys-devices-virtual-block-dm\x2d0.device: Job sys-devices-virtual-block-dm\x2d0.device/stop timed out.
[ 3956.372774] systemd[1]: Timed out stopping /sys/devices/virtual/block/dm-0.
[ 3956.375485] systemd[1]: sys-devices-virtual-block-dm\x2d0.device: Job sys-devices-virtual-block-dm\x2d0.device/stop failed with result 'timeout'.
[ 3956.375509] systemd[1]: session-2.scope: Stopping timed out. Killing.
[ 3956.375570] systemd[1]: session-2.scope: Killing process 3576 (qubes-guid) with signal SIGKILL.
[ 3956.376535] systemd[1]: Stopped Session 2 of user ctor.
[ 3956.381215] systemd[1]: session-2.scope: Unit entered failed state.
[ 3956.381915] systemd[1]: Removed slice User Slice of ctor.
[ 3956.385125] systemd[1]: Stopping Login Service...
[ 3956.389095] systemd[1]: Stopping Permit User Sessions...
[ 3956.393457] systemd[1]: Stopped Permit User Sessions.
[ 3956.396533] systemd[1]: Stopped Start Qubes VM sys-firewall.
[ 3956.399094] systemd[1]: Stopped Start Qubes VM sys-net.
[ 3956.402260] systemd[1]: Removed slice system-qubes\x2dvm.slice.
[ 3956.405398] systemd[1]: Stopping Qubes memory information reporter...
[ 3956.409027] systemd[1]: Stopped Qubes memory information reporter.
[ 3956.413280] systemd[1]: Stopping Qubes Dom0 startup setup...
[ 3956.433905] preshutdown[9971]: Name                                        ID   Mem VCPUs    State   Time(s)
[ 3956.438400] preshutdown[9971]: Domain-0                                     0  4071     6     r-----     706.6
[ 3956.439730] preshutdown[9971]: sys-net                                      1   384     2     -b----      10.7
[ 3956.441032] preshutdown[9971]: sys-net-dm                                   2   144     1     -b----     151.6
[ 3956.442332] preshutdown[9971]: sys-firewall                                 3  3983     2     -b----      15.0
  • Looks like it's /usr/lib/systemd/system/udisks2.service but I don't remember how I figured it out! So an answer is still welcome. – Marcus Linsner Sep 4 '18 at 0:01
  • No, that wasn't it: it's not udisks2.service ! (funny thing is, the next boot worked as if it were it, but next after that is back to timeouts, without me changing anything) – Marcus Linsner Sep 4 '18 at 0:28
2

You can use the systemctl show <device> to see more details on the unit file that's handling the *.device.

For example, on my CentOS 7.x system if we look through the journalctl -b for some devices:

$ journalctl -b | grep 'systemd\[1\]: dev-disk-by' | head -3
Sep 03 17:48:57 centos7 systemd[1]: dev-disk-by\x2dpath-pci\x2d0000:00:01.1\x2data\x2d1.0.device changed dead -> plugged
Sep 03 17:48:57 centos7 systemd[1]: dev-disk-by\x2did-ata\x2dVBOX_HARDDISK_VBc5aaf476\x2df419b1f1.device changed dead -> plugged
Sep 03 17:48:57 centos7 systemd[1]: dev-disk-by\x2duuid-013c42ea\x2daa00\x2d4713\x2d926a\x2daca57c0bd552.device changed dead -> plugged

Now if we inquire to systemd about one of these .device files:

$ systemctl show 'dev-disk-by\x2duuid-013c42ea\x2daa00\x2d4713\x2d926a\x2daca57c0bd552.device'
SysFSPath=/sys/devices/pci0000:00/0000:00:01.1/ata1/host0/target0:0:0/0:0:0:0/block/sda/sda2
Id=dev-disk-by\x5cx2duuid-013c42ea\x5cx2daa00\x5cx2d4713\x5cx2d926a\x5cx2daca57c0bd552.device
Names=dev-disk-by\x5cx2duuid-013c42ea\x5cx2daa00\x5cx2d4713\x5cx2d926a\x5cx2daca57c0bd552.device
Following=sys-devices-pci0000:00-0000:00:01.1-ata1-host0-target0:0:0-0:0:0:0-block-sda-sda2.device
Description=VBOX_HARDDISK 2
LoadState=loaded
ActiveState=active
SubState=plugged
InactiveExitTimestamp=Mon 2018-09-03 21:48:59 EDT
InactiveExitTimestampMonotonic=4178671
ActiveEnterTimestamp=Mon 2018-09-03 21:48:59 EDT
ActiveEnterTimestampMonotonic=4178671
ActiveExitTimestampMonotonic=0
InactiveEnterTimestampMonotonic=0
CanStart=no
CanStop=no
CanReload=no
CanIsolate=no
StopWhenUnneeded=no
RefuseManualStart=no
RefuseManualStop=no
AllowIsolate=no
DefaultDependencies=yes
OnFailureJobMode=replace
IgnoreOnIsolate=yes
IgnoreOnSnapshot=yes
NeedDaemonReload=no
JobTimeoutUSec=1min 30s
JobTimeoutAction=none
ConditionResult=no
AssertResult=no
ConditionTimestampMonotonic=0
AssertTimestampMonotonic=0
Transient=no

NOTE: That the \x2d is actually the ASCII code for a dash.

$ printf '\x2d\n'
-

After=?

What does one set in other services so that they'll start after the .device files? For this you'll want to use this, After=system.device. You can see this device's status like this, though it isn't very telling:

$ systemctl status system.device
● system.device
   Loaded: loaded
   Active: inactive (dead)

Sep 03 21:49:52 centos7 systemd[1]: Collecting system.device

NOTE: You can also interchangeably use systemd.device.

References

  • Is there a parent service that's starting/stopping those? I need to be able to do After=thatparent.service on my service, so that my service stops first before these disks get unmounted. I mean for example I used After=dev-block-253:0.device and it worked for 2 consecutive reboots, as expected; but the 3rd one acted as if the change wasn't made so it timed out again: gist.github.com/constantoverride/… – Marcus Linsner Sep 4 '18 at 1:17
  • 1
    @MarcusLinsner - for the After= you want to make it After=system.device. – slm Sep 4 '18 at 1:50
  • 1
    Perhaps somewhat unexpectedly, this also works: systemctl show '*.device' (or systemctl show \*.device ) – Marcus Linsner Sep 4 '18 at 8:20
  • How does this comment by a systemd dev. affect this q/a ? It seems like I should be looking for a service (other than system(d).service) that's starting those DM/LVM, and yet something like lvm2-pvscan@253:0.service doesn't seem to be the answer because devices still stop(and wait until the 90sec timeout) before my service's ExecStop, even tho they shouldn't be stopped before my serv – Marcus Linsner Sep 11 '18 at 20:03

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.