[systemd-devel] Long waiting for swap device

[Nikolai Zhubr]

Hi,

Looking at bootlog console messages, I noticed something strange.
systemd says:

Expecting device dev-disk-by-x2duuid-4c25...
... and soon adds:
A start job is running for dev-disk-by-x2duuid-4c25...
... and it keeps waiting for some seconds.
Also, "systemd-analyze blame" lists "dev-disk-by-x2duuid-4c25..." among 
top time-eaters.

The "uuid-4c25..." device is actually a swap partition (specified in 
fstab), so systemd is correct that this device needs to appear and be 
activeted as swap. If it matters, swap is located on raid1 device 
(/dev/md1) which consists of /dev/sda5 and /dev/sdb5, while physical 
disks sda and sdb are just regular sata harddisks of equal geometry.

However, AFAICS the said "uuid-4c25..." device is already present before 
the "Expecting device ..." message appears. I think this can also be 
illustrated by journalctl | grep 4c25:
---------------- cut ----------------
17:36:56 kernel: Kernel command line: 
BOOT_IMAGE=/boot/vmlinuz-3.16.6-2-desktop 
root=UUID=588d9a9c-4c4e-4400-9e2b-a79f5fce670e 
resume=/dev/disk/by-uuid/4c25dd37-c555-4fbf-8349-f1470d0e924c 
systemd.log_level=debug showopts vga=normal
17:36:56 systemd[1]: Installed new job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device/start 
as 34
17:36:56 systemd[1]: Expecting device 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device...
17:36:57 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device 
changed dead -> plugged
17:36:57 systemd[1]: Job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device/start 
finished, result=done
17:36:57 systemd[1]: Found device 
/dev/disk/by-uuid/4c25dd37-c555-4fbf-8349-f1470d0e924c.
17:36:58 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device 
changed dead -> plugged
17:37:11 systemd[1]: Installed new job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap/start 
as 122
17:37:11 systemd[1]: Installed new job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device/start 
as 123
17:37:12 systemd[1]: Merged into installed job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap/start 
as 122
17:37:12 systemd[1]: Merged into installed job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device/start 
as 123
17:37:18 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap changed 
dead -> activating
17:37:13 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device 
changed dead -> plugged
17:37:13 systemd[1]: Job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.device/start 
finished, result=done
17:37:13 systemd[1]: Found device 
/dev/disk/by-uuid/4c25dd37-c555-4fbf-8349-f1470d0e924c.
17:37:18 systemd[632]: Executing: /sbin/swapon 
/dev/disk/by-uuid/4c25dd37-c555-4fbf-8349-f1470d0e924c
17:37:18 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap changed 
activating -> activating-done
17:37:18 systemd[1]: Job 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap/start 
finished, result=done
17:37:18 systemd[1]: Activated swap 
/dev/disk/by-uuid/4c25dd37-c555-4fbf-8349-f1470d0e924c.
17:37:18 systemd[1]: Child 632 belongs to 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap
17:37:18 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap swap 
process exited, code=exited status=0
17:37:18 systemd[1]: 
dev-disk-by\x2duuid-4c25dd37\x2dc555\x2d4fbf\x2d8349\x2df1470d0e924c.swap changed 
activating-done -> active
---------------- cut ----------------
Here I'd compare this:
17:36:57 systemd[1]: Found device /dev/disk/by-uuid/4c25...
...and
17:37:18 systemd[632]: Executing: /sbin/swapon /dev/disk/by-uuid/4c25...
-- the delay is over 20 seconds! Ok, there are some other actions taken 
in between, unrelated of swap, and they consume some time too, but 
still, why waiting for device that is already available?
Any hints?

Thank you in advance,
Nikolai