systemd Timed out waiting for device swap and file system check

[B.]

My Ubuntu 15.04 did not start --or took so long that I switched back to upstart!

ISSUE: (systemd during the boot)

Timed out waitingfor device dev-disk-by\x2duuid-... (swap)
Dependency failed for /dev/disk/by-uuid/... (swap)
Dependency failed for Swap.
Timed out waiting for device dev-sdaX.device (swap)
Dependency failed for Swap Partition.
Failed to start udev Wait for Complete Device Initialization.
See "systemctl status systemd-udev-settle.service" for details.
    Starting File System Check on Root Device...
    Starting Copy rules generated while the root was ro...
(1 of 2) A start job is running for File System Check on Root Device (3min 28s / no limit)
...
     No tainted 3.19.0-18-generic #18-Ubuntu
"echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
INFO: task systemd-udevd:336 blocked for more than 120 seconds.
...
INFO: task systemd-udevd:338 blocked for more than 120 seconds.
...
INFO: task systemd-udevd:346 blocked for more than 120 seconds.
...
(1 of 2) A start job is running for File System Check on Root Device (4min 3s / no limit)

WORKAROUND:

apt-get -qq -y install upstart-sysv # switch back to upstart
http://linux.softpedia.com/blog/Ubuntu-15-04-Users-Can-Switch-Off-Systemd-and-Use-Upstart-479373.shtml
P.S. don't ask me to go back to systemd-sysv... I am fine with upstart....

TECHNICAL DETAILS:

$ lsb_release -r
Release: 15.04

$ uname -r
3.19.0-18-generic

$ sudo dmidecode -s system-product-name
MacBookPro8,2

$ grep "^GRUB_CMDLINE_LINUX_DEFAULT" /etc/default/grub
GRUB_CMDLINE_LINUX_DEFAULT="transparent_hugepage=always intel_iommu=on acpi_irq_nobalance cgroup_enable=memory swapaccount=1 libata.force=noncq modeset=1 hybridopts=ON,IGD,OFF i915.modeset=0 radeon.modeset=1 radeon.dpm=1 radeon.audio=1 i915.lvds_channels=2 quirks.mbp_force_ahci=1 acpi_backlight=vendor reboot=pci"

$ cat /etc/fstab
# <file system> <mount point> <type> <options> <dump> <pass>
# / was on /dev/sda5 during installation
UUID=6619a7e9-4b94-4e9b-8dbe-4110f89dde74 / ext4 errors=remount-ro 0 1
# swap was on /dev/sda6 during installation
UUID=813e9dc2-c678-4959-ac89-e6660f886942 none swap sw 0 0

# lsblk -f
NAME FSTYPE LABEL UUID MOUNTPOINT
sda
├─sda1 vfat EFI 67E3-17ED
├─sda2 hfsplus Macintosh HD 2ba5bbc1-fff0-36ea-ade4-140386274279
├─sda3 hfsplus Recovery HD 9e776f16-ceb4-37e6-b4ce-4e75c1db5444
├─sda4
├─sda5 ext4 6619a7e9-4b94-4e9b-8dbe-4110f89dde74 /
└─sda6 swap 813e9dc2-c678-4959-ac89-e6660f886942 [SWAP]
sr0

# blkid
/dev/sda1: LABEL="EFI" UUID="67E3-17ED" TYPE="vfat" PARTLABEL="EFI System Partition" PARTUUID="5d71ff71-9843-473d-90e7-4c780c8a494d"
/dev/sda2: UUID="2ba5bbc1-fff0-36ea-ade4-140386274279" LABEL="Macintosh HD" TYPE="hfsplus" PARTLABEL="Macintosh HD" PARTUUID="4e4c2249-24f8-4229-9325-d4aafd7ac093"
/dev/sda3: UUID="9e776f16-ceb4-37e6-b4ce-4e75c1db5444" LABEL="Recovery HD" TYPE="hfsplus" PARTLABEL="Recovery HD" PARTUUID="a986e3e1-ed3b-44bb-a75b-87b54434380d"
/dev/sda5: UUID="6619a7e9-4b94-4e9b-8dbe-4110f89dde74" TYPE="ext4" PARTUUID="9d860cb1-1334-4f79-a07a-01b8818c4aab"
/dev/sda6: UUID="813e9dc2-c678-4959-ac89-e6660f886942" TYPE="swap" PARTUUID="bf1271f6-8d51-4510-8979-666c9546f1f3"
/dev/sda4: PARTUUID="2b731a42-bd29-4548-8f0e-a9889ee9486b"

[B. (b-deactivatedaccount-deactivatedaccount)]

Please note that my swap is NOT encrypted so it's not related to bug 1440098 or 953875

[Steve Langasek (vorlon)]

> P.S. don't ask me to go back to systemd-sysv... I am fine with upstart....

upstart is not a supported option in Ubuntu 15.04 and later. Are you willing to help the Ubuntu developers debug this issue? That will probably require you booting systemd to confirm the fix.

Please attach /etc/fstab from your system, and show the output of 'swapon' when booted with upstart.

[Martin Pitt (pitti)]

Thanks for your report. I don't see anything immediately wrong with your /etc/fstab, blkid looks fine and has matching UUIDs. So I'm afraid I need a full log to see what happened.

In the grub boot menu under "Advanced options", please select the one-time boot with systemd (you don't need to change packages for that), 'e'dit that line, drop any "splash" or "quiet" and instead append "debug systemd.debug-shell", then boot with Ctrl-X.

Once it hangs, you should be able to do Ctrl-Alt-F9 and land in the debug shell. There, run "journalctl -ab > /root/journal.txt". Reboot again (with upstart), and attach /root/journal.txt here. Thanks!

[B. (b-deactivatedaccount-deactivatedaccount)]

> Please attach /etc/fstab from your system, and show the output of 'swapon' when booted with upstart.

@vorlon content of fstab see "Bug Description"

$ sudo swapon
NAME TYPE SIZE USED PRIO
/dev/sda6 partition 7.9G 11.5M -1

Ok, I will try to go back to systemd for science ;-)
$ sudo apt-get install systemd-sysv

@pitti

I will try that. Thanks!

[B. (b-deactivatedaccount-deactivatedaccount)]

@pitti

I am unable to reproduce it with 3.19.0-20 nor 3.19.0-18.
So I installed back systemd-sysv and I will do the debug stuff
next time I have the issue.

I guess the issue was related to a strange state of swap or the disk
and after booting once with upstart something fixed it. fsck??

[B. (b-deactivatedaccount-deactivatedaccount)]

It could be related that ext4 was in a bad state and systemd was not able to use it
then upstart executed fsck to fix it and now I can again use systemd.

# /var/log/syslog.4.gz
$ zgrep -h "fsck" /var/log/*.gz
Jun 8 08:43:06 mbp kernel: [1788385.038996] FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Jun 8 10:48:10 mbp systemd-fsck[971]: /dev/sda5: clean, 448286/17760256 files, 35731755/71025664 blocks
Jun 8 10:48:10 mbp kernel: [ 4.748519] systemd[1]: Listening on fsck to fsckd communication Socket.
Jun 8 10:48:10 mbp kernel: [ 4.750175] systemd[1]: Starting fsck to fsckd communication Socket.
Jun 8 11:08:54 mbp systemd-fsck[943]: /dev/sda5: clean, 447436/17760256 files, 35695088/71025664 blocks
Jun 8 11:08:54 mbp kernel: [ 3.809333] systemd[1]: Listening on fsck to fsckd communication Socket.
Jun 8 11:08:54 mbp kernel: [ 3.809392] systemd[1]: Starting fsck to fsckd communication Socket.
Jun 8 11:11:50 mbp systemd-fsck[946]: /dev/sda5: clean, 447438/17760256 files, 35715637/71025664 blocks
Jun 8 11:11:50 mbp kernel: [ 3.736279] systemd[1]: Listening on fsck to fsckd communication Socket.
Jun 8 11:11:50 mbp kernel: [ 3.737878] systemd[1]: Starting fsck to fsckd communication Socket.

zgrep -h systemd /var/log/syslog.4.gz > systemd-2015-06-08.log

[Martin Pitt (pitti)]

The sdb1 one is most likely an USB stick (FAT, not ext4). Your ext4 root partition is sda5 which is shown as clean now. Could still be that a previous fsck cured it, of course -- this wouldn't appear in /var/log/syslog as it happens very early at boot already while the root partition is still readonly. It would be in the persistant journal, but too late to retroactively enable that..

If it works now, then there's not much that we can do to still debug this, I'm afraid. So I'm closing this for now.

Thanks!

[Thomas Dreibholz (dreibh)]

I have noticed this problem on 2 machines upgraded from Ubuntu 14.04 to Ubuntu 16.04, when trying to boot the upgraded system for the first time. The really bad issue is that after timing out, the system is going to hang with messages like:
[58Z?Z1.5?Z840] INFO task systemd:21547 blocked for more than 120 seconds.
This is particularly bad if the system is remote.

(sysctls to consider these hangs as panics, and reboot a paniced kernel automatically end in a loop: boot -> mount problem -> hang -> reboot -> ...)

Unfortunately, I was not able to find out what actually caused the mounting problem (in my case: /home and swap). Booting from CD did not reveal anything interesting (manually did fsck), and after rebooting again it worked without problems.

[Alexander Adam (7ql6)]

I'm having the same issue now. I upgraded from Ubuntu 16.04 to 16.10.
I was able to boot twice into a running system, but I had no luck the other times besides from these two times.

However, this gives you the chance to, hopefully, solve this issue.
And as I'm landing in the recovery console with decrypted and mounted root partition I guess it may be solvable.

I can't really remember how the cryptsetup stuff worked so it may really be related to some changed / referenced uuids?

I found posts from other people with the same issue but none of them seem to got it solved.

[Alexander Adam (7ql6)]

I just found out that running "cryptdisks_start cryptswap1" allows me to activate the swap with swapon.
So I guess the UUID references are fine and there is some systemd-crypto-issue going on.

[Alexander Adam (7ql6)]

Ah, I'm sorry. I just realized this is rather this issue:
https://bugs.launchpad.net/ubuntu/+source/ecryptfs-utils/+bug/953875

[Alexander Adam (7ql6)]

Okay, sorry I was wrong again. The other issue just handles the cryptswap-stuff which seems to be an issue for years in Ubuntu (and gets closed most of the times).

However, I was finally able to boot my system and wanted to share for others who might be run into this issue with systemd timeouts:

I added "selinux=1 enforcing=0" to kernel boot parameters.
I have no idea why this helps but I found it here:

http://unix.stackexchange.com/questions/279987/fedora-24-wont-boot-after-dnf-upgrade#answer-280298