Arch Linux

wlcrls47

Member

Registered: 2015-08-01

Posts: 8

"systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

"systemctl reboot":
[  OK  ] Reached target Shutdown.
[      ] watchdog watchdog0: watchdog did not stop!
[      ] watchdog watchdog0: watchdog did not stop!
[      ] cgroup: option or name mismatch, new: 0x0 "", old: 0x4 "systemd"
[      ] shutdown[1]: Failed to finalize  DM devices, ignoring
[      ] INFO: task shutdown:1 blocked for more than 120 seconds.
[      ]       Not tainted 4.1.3-1-ARCH #1
[      ] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
It then repeats the INFO-echo lines forever with 2 minutes in between each set, until I manually hit the power switch.

Fresh arch install, kernel 4.1.3-1, lvm2 2.02.125-1, mdadm 3.3.2-2
I am running lvm
I have an mdadm raid1 of /dev/md0 for swap of 3 LVM logical volumes
I have a btrfs raid1 of 3 LVM logical volumes
I ran "mdadm --detail --scan > /mountpoint/etc/mdadm.conf" during installation
I added "mdadm_udev lvm2" to /etc/mkinitcpio.conf between "block" and "filesystemd" during installation, then ran "mkinitcpio -p linux"
"dmsetup -ls" properly shows all 3 of my LVM logical volumes

wlcrls47

Member

Registered: 2015-08-01

Posts: 8

Re: "systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

upstream systemd says this bug isn't them, but didn't give guidance on what it might be.

wlcrls47

Member

Registered: 2015-08-01

Posts: 8

Re: "systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

Kernel Rebooting Works

# echo 1 > /proc/sys/kernel/sysrq
# sync && echo b > /proc/sysrq-trigger

Shutdown logs
adding "systemd.log_level=debug systemd-log_target=kmsg log_buf_len=1M enforcing=0" to kernel parameters, and creating /usr/lib/systemd/system-shutdown/debug.sh of:

#!/bin/sh
mount -o remount,rw /
dmesg > /shutdown-log.txt
mount -o remount,ro /

shows:

[ 759.193902] systemd[1]: Assertion 'r >= 0' failed at src/libsystemd/sd-event/sd-event.c:484, function source_io_unregister(). Ignoring.
[ 759.193956] systemd[1]: Hardware watchdog 'iTCO_wdt', version 0
[ 759.193969] systemd[1]: Set hardware watchdog to 10min.
[ 759.193978] watchdog watchdog0: watchdog did not stop!
[ 759.197079] systemd-shutdown[1]: Sending SIGTERM to remaining processes...
[ 759.208390] systemd-udevd[342]: Unload module index
[ 759.208454] systemd-udevd[342]: Unloaded link configuration context.
[ 759.750116] systemd-journald[294]: Received SIGTERM from PID 1 (systemd-shutdow).
[ 759.750126] systemd-journald[294]: systemd-journald stopped as pid 294
[ 759.868629] systemd-shutdown[1]: Sending SIGKILL to remaining processes...
[ 759.878623] systemd-shutdown[1]: Hardware watchdog 'iTCO_wdt', version 0
[ 759.878867] systemd-shutdown[1]: Unmounting file systems.
[ 759.927208] BTRFS info (device dm-5): disk space caching is enabled
[ 759.968498] BTRFS info (device dm-5): disk space caching is enabled
[ 759.968513] systemd-shutdown[1]: All filesystems unmounted.
[ 759.968518] systemd-shutdown[1]: Deactivating swaps.
[ 759.968587] systemd-shutdown[1]: All swaps deactivated.
[ 759.968591] systemd-shutdown[1]: Detaching loop devices.
[ 759.968661] systemd-shutdown[1]: device-enumerator: scan all dirs
[ 759.968680] systemd-shutdown[1]: device-enumerator: scanning /sys/bus
[ 759.968715] systemd-shutdown[1]: device-enumerator: scanning /sys/class
[ 759.968780] systemd-shutdown[1]: All loop devices detached.
[ 759.968784] systemd-shutdown[1]: Detaching DM devices.
[ 759.968808] systemd-shutdown[1]: device-enumerator: scan all dirs
[ 759.968819] systemd-shutdown[1]: device-enumerator: scanning /sys/bus
[ 759.968841] systemd-shutdown[1]: device-enumerator: scanning /sys/class
[ 759.970098] systemd-shutdown[1]: Detaching DM 254:5.
[ 759.970122] systemd-shutdown[1]: Could not detach DM /dev/dm-5: Device or resource busy
[ 759.970126] systemd-shutdown[1]: Detaching DM 254:4.
[ 759.970137] systemd-shutdown[1]: Could not detach DM /dev/dm-4: Device or resource busy
[ 759.970141] systemd-shutdown[1]: Detaching DM 254:3.
[ 759.970151] systemd-shutdown[1]: Could not detach DM /dev/dm-3: Device or resource busy
[ 759.970155] systemd-shutdown[1]: Detaching DM 254:2.
[ 759.970165] systemd-shutdown[1]: Could not detach DM /dev/dm-2: Device or resource busy
[ 759.970168] systemd-shutdown[1]: Detaching DM 254:1.
[ 759.970180] systemd-shutdown[1]: Could not detach DM /dev/dm-1: Device or resource busy
[ 759.970184] systemd-shutdown[1]: Detaching DM 254:0.
[ 759.970194] systemd-shutdown[1]: Could not detach DM /dev/dm-0: Device or resource busy
[ 759.970199] systemd-shutdown[1]: Not all DM devices detached, 6 left.
[ 759.970203] systemd-shutdown[1]: Cannot finalize remaining DM devices, continuing.
[ 759.970800] systemd-shutdown[915]: Spawned /usr/lib/systemd/system-shutdown/mdadm.shutdown as 916.
[ 759.970932] systemd-shutdown[915]: Spawned /usr/lib/systemd/system-shutdown/debug.sh as 917.
[ 759.974624] BTRFS info (device dm-5): disk space caching is enabled
[ 759.974732] systemd-shutdown[915]: /usr/lib/systemd/system-shutdown/mdadm.shutdown succeeded.

:1, :3, and :5 correspond to LVM logical volumes that make up my root partition via btrfs raid1.  (No subpartitions.)  :0 :2 and :4 correspond to LVM logical volumes that make up my partitions that make a swap partition via mdadm raid1.

wlcrls47

Member

Registered: 2015-08-01

Posts: 8

Re: "systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

Hmm.  I tried going back to my first btrfs/snapper snapshot, and it rebooted fine.  I started binary searching for when it broke, and got back to my latest (before I went backwards) snapshot.

This made me discover that if I reboot really quickly (so kernel logs 30 seconds or so) it reboots with a 10 second delay or so, but it reboots.

If I let uptime go to 10 minutes, then it goes back to not rebooting.

I'm going to try discovering how long of an uptime is needed before it won't reboot -- or if it's not a cutoff point, but a linear/curved relationship that eventually grows too large.

I'm also going to try discovering if my initial install snapshot won't reboot after a bit of uptime.

Unfortunately, these tests are going to take time since there's a lot of waiting involved.

Sadly, the systemd debug shell (tty9 = root shell) which starts early in the boot process and stays until late in the reboot process is gone by the time it "hangs" so I can't query systemctl at all.

Last edited by wlcrls47 (2015-08-02 04:01:06)

Rorschach

Member

From: Ankh-Morpork

Registered: 2008-11-07

Posts: 143

Re: "systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

Same problem here without LVM but with DM-Crypt. Kernel shutdown with:

# sync && poweroff -f

working. Shutdown with systemd is not working and I'm getting similar but a bit different messages as you did:

[      ] shutdown[1]: Failed to finalize  file systems, DM devices, ignoringabc288e299.04c5-home .
[      ] INFO: task systemd-logind:469 blocked for more than 120 seconds.
[      ]       Not tainted 4.1.3-1-ARCH #1
[      ] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

So me too is having problems with DM devices but my messages are slightly different then yours.

Rorschach

Member

From: Ankh-Morpork

Registered: 2008-11-07

Posts: 143

Re: "systemctl reboot" never reboots on 223 with lvm, mdadm raid, btrfs ra

Maybe this is related but im on the current kernel and it's still a problem: https://bbs.archlinux.org/viewtopic.php?id=207096 , heres a bug report: https://bugs.archlinux.org/task/47734

Last edited by Rorschach (2016-02-06 16:21:45)