systemd doesn't umount (encrypted) /home and /tmp on shutdown

gegenschall · 2013-10-09 17:15:12

Hi all,

as this is my first post in this BBS, I hope I'm actually posting in the correct forum. I also did some research but couldn't really find answers.

I have a problem with systemd on shutdown. It doesn't unmount my encrypted home partition (and does not close the LUKS partition) and the /tmp partition. The corresponding output from journalctl would be this:

Oct 09 16:08:18 failenovo systemd[1]: Stopping Local File Systems.
Oct 09 16:08:18 failenovo systemd[1]: Stopped target Local File Systems.
Oct 09 16:08:18 failenovo systemd[1]: Unmounting /data...
Oct 09 16:08:18 failenovo systemd[1]: Unmounting /boot...
Oct 09 16:08:18 failenovo systemd[1]: Unmounting /home...
Oct 09 16:08:18 failenovo umount[3995]: umount: /home: target is busy.
Oct 09 16:08:18 failenovo umount[3995]: (In some cases useful info about processes that use
Oct 09 16:08:18 failenovo umount[3995]: the device is found by lsof(8) or fuser(1))
Oct 09 16:08:18 failenovo systemd[1]: Unmounting Temporary Directory...
Oct 09 16:08:18 failenovo systemd[1]: home.mount mount process exited, code=exited status=32
Oct 09 16:08:18 failenovo systemd[1]: Failed unmounting /home.
Oct 09 16:08:18 failenovo systemd[1]: Stopping File System Check on /dev/disk/by-uuid/a9395b0a-e3f8-41d7-9feb-d433173fd5ab...
Oct 09 16:08:18 failenovo systemd[1]: Stopped File System Check on /dev/disk/by-uuid/a9395b0a-e3f8-41d7-9feb-d433173fd5ab.
Oct 09 16:08:18 failenovo systemd[1]: Stopping /sys/devices/virtual/block/dm-1.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/sda1.
Oct 09 16:08:18 failenovo systemd[1]: Unmounted /boot.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/disk/by-partuuid/28e18189-6b46-40b5-82f8-d550ee3df47a.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/disk/by-partlabel/Linux\x20swap.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/disk/by-id/wwn-0x5000cca615e3f206-part1.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/disk/by-id/ata-HITACHI_HTS543232A7A384_E2434243JK29XK-part1.
Oct 09 16:08:18 failenovo systemd[1]: Deactivated swap /dev/disk/by-uuid/4903864c-36f8-4f05-a722-ed726c9ae492.
Oct 09 16:08:18 failenovo umount[3997]: umount: /tmp: target is busy.
Oct 09 16:08:18 failenovo umount[3997]: (In some cases useful info about processes that use
Oct 09 16:08:18 failenovo umount[3997]: the device is found by lsof(8) or fuser(1))
Oct 09 16:08:18 failenovo systemd[1]: tmp.mount mount process exited, code=exited status=32
Oct 09 16:08:18 failenovo systemd[1]: Failed unmounting Temporary Directory.
Oct 09 16:08:18 failenovo systemd[1]: Unmounted /data.
Oct 09 16:08:18 failenovo systemd[1]: Stopping Local File Systems (Pre).
Oct 09 16:08:18 failenovo systemd[1]: Stopped target Local File Systems (Pre).
Oct 09 16:08:18 failenovo systemd[1]: Stopping Remount Root and Kernel File Systems...
Oct 09 16:08:18 failenovo systemd[1]: Stopped Remount Root and Kernel File Systems.
Oct 09 16:08:18 failenovo systemd[1]: Starting Shutdown.
Oct 09 16:08:18 failenovo systemd[1]: Reached target Shutdown.
Oct 09 16:08:23 failenovo systemd-cryptsetup[3989]: Failed to deactivate: Device or resource busy
Oct 09 16:08:23 failenovo systemd[1]: systemd-cryptsetup@home.service: control process exited, code=exited status=1
Oct 09 16:08:23 failenovo systemd[1]: Stopped Cryptography Setup for home.
Oct 09 16:08:23 failenovo systemd[1]: Unit systemd-cryptsetup@home.service entered failed state.
Oct 09 16:08:23 failenovo systemd[1]: Starting Unmount All Filesystems.
Oct 09 16:08:23 failenovo systemd[1]: Reached target Unmount All Filesystems.

Now, with the usual sysv-init this wouldn't be a problem but with systemd (which I'm new to) this poses a problem. I don't know where to start debugging this issue, really. I haven't found a way to run a script directly before and after the umount.target units starts so I can't really see which files are open or what the problem is at this point.
Is it possible to drop to a shell on such errors and inspect the problem manually? Or does anyone have a suggestion why systemd doesn't want to unmount these filesystems?

Here's my /etc/fstab:

# <file system>	<dir>	<type>	<options>	<dump>	<pass>
# /dev/mapper/root LABEL=ROOT
UUID=27fed041-7765-4f63-a895-a7592113165b	/         	ext4      	rw,relatime,data=ordered,discard	0 1

# /dev/mapper/home LABEL=HOME
UUID=a9395b0a-e3f8-41d7-9feb-d433173fd5ab	/home     	ext4      	rw,relatime,data=ordered,discard	0 2

# /dev/sdb1
UUID=1573-8C74      	/boot/ 	vfat      	rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro	0 2

# /dev/sda1 LABEL=SWAP
UUID=f5097167-6e12-4548-8bef-5f83942a1848	none	swap	defaults	0	0

# /dev/sda2 LABEL=DATA
UUID=dffd1518-d3b5-4d05-8b13-76e6fd841963	/data		ext4		defaults	0 2

and my /etc/crypttab:

# <name>       <device>         <password>              <options>
home	UUID=01f3da5d-1ca0-4bf2-b5a1-cfe69c597707	/etc/keys/home.key	luks,discard

If you need more information, please do tell! Thanks in advance.

Cheers,
gegenschall

cfr · 2013-10-10 01:05:19

Welcome to the forums.

I'm not sure about this but do you need the shutdown hook in the initramfs and, if so, are you using it? I know this is needed if / is encrypted - not sure about other cases.

gegenschall · 2013-10-10 09:37:40

I didn't have the shutdown hook in my HOOKS, but adding it didn't work either. Logging out, stopping gdm.service and unmounting /home does however work without problems.

teateawhy · 2013-10-10 15:18:24

gegenschall wrote:

Here's my /etc/fstab:
# <file system> <dir> <type> <options> <dump> <pass>
# /dev/mapper/root LABEL=ROOT
UUID=27fed041-7765-4f63-a895-a7592113165b / ext4 rw,relatime,data=ordered,discard 0 1
# /dev/mapper/home LABEL=HOME
UUID=a9395b0a-e3f8-41d7-9feb-d433173fd5ab /home ext4 rw,relatime,data=ordered,discard 0 2

I think you should use /dev/mapper/name instead of UUIDs for all encrypted partitions in your fstab.
https://wiki.archlinux.org/index.php/Dm … nts_system

gegenschall wrote:

I didn't have the shutdown hook in my HOOKS, but adding it didn't work either.

Have you run the

mkinitcpio

command to regenerate the initramfs?
https://wiki.archlinux.org/index.php/Dm … _initramfs

Recently i set up encryption on my home partition, and your post made me check journalctl for errors. But for me the unmounting works.

gegenschall · 2013-10-11 11:58:50

teateawhy wrote:

I think you should use /dev/mapper/name instead of UUIDs for all encrypted partitions in your fstab.

Didn't make any difference...

teateawhy wrote:

Have you run the
mkinitcpio
command to regenerate the initramfs?

Yes, I did. As long as the shutdown hook doesn't need to be in any specific position inside the HOOKS array it didn't work.

teateawhy wrote:

Recently i set up encryption on my home partition, and your post made me check journalctl for errors. But for me the unmounting works.

Yeah, I think I'll remove encryption or stop rebooting as I had the first remount-ro today. :-(

aoba · 2013-10-11 20:01:20

I have the same problem as @gegenschall. My setup (and the resulting behavior) is very similar.

journalctl -b -1

Oct 09 22:08:39 ohana systemd[1]: Stopping Local File Systems.
Oct 09 22:08:39 ohana systemd[1]: Stopped target Local File Systems.
Oct 09 22:08:39 ohana systemd[1]: Unmounting /home...
Oct 09 22:08:39 ohana systemd[1]: Unmounting /storage...
Oct 09 22:08:39 ohana systemd[1]: Unmounting /var...
Oct 09 22:08:39 ohana systemd[1]: Unmounting /tmp...
Oct 09 22:08:39 ohana systemd[1]: Unmounting /boot...
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/mapper/linux-swap.
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/linux/swap.
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/disk/by-id/dm-uuid-LVM-DevEGGWf3oc8GE2g06c6XaLVUQEgo9cTTSwqNIhBSQfWKqAKYdL5k
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/disk/by-id/dm-name-linux-swap.
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/disk/by-uuid/f8b1e59e-9804-44f0-af79-66810ee49206.
Oct 09 22:08:39 ohana systemd[1]: Deactivated swap /dev/dm-2.
Oct 09 22:08:39 ohana umount[11755]: umount: /var: target is busy.
Oct 09 22:08:39 ohana umount[11755]: (In some cases useful info about processes that use
Oct 09 22:08:39 ohana umount[11755]: the device is found by lsof(8) or fuser(1))
Oct 09 22:08:39 ohana umount[11756]: umount: /tmp: target is busy.
Oct 09 22:08:39 ohana umount[11756]: (In some cases useful info about processes that use
Oct 09 22:08:39 ohana umount[11756]: the device is found by lsof(8) or fuser(1))
Oct 09 22:08:39 ohana systemd[1]: var.mount mount process exited, code=exited status=32
Oct 09 22:08:39 ohana systemd[1]: Failed unmounting /var.
Oct 09 22:08:39 ohana systemd[1]: tmp.mount mount process exited, code=exited status=32
Oct 09 22:08:39 ohana systemd[1]: Failed unmounting /tmp.
Oct 09 22:08:39 ohana systemd[1]: home.mount mount process exited, code=exited status=32
Oct 09 22:08:39 ohana systemd[1]: Failed unmounting /home.
Oct 09 22:08:39 ohana systemd[1]: Stopping File System Check on /dev/disk/by-uuid/98691163-fffa-4321-984c-3ba237083524...
Oct 09 22:08:39 ohana systemd[1]: Stopped File System Check on /dev/disk/by-uuid/98691163-fffa-4321-984c-3ba237083524.
Oct 09 22:08:39 ohana systemd[1]: Stopping /sys/devices/virtual/block/dm-6.
Oct 09 22:08:39 ohana umount[11753]: umount: /home: target is busy.
Oct 09 22:08:39 ohana umount[11753]: (In some cases useful info about processes that use
Oct 09 22:08:39 ohana umount[11753]: the device is found by lsof(8) or fuser(1))
Oct 09 22:08:39 ohana systemd[1]: Unmounted /storage.
Oct 09 22:08:39 ohana systemd[1]: Unmounted /boot.
Oct 09 22:08:39 ohana systemd[1]: Stopping Local File Systems (Pre).
Oct 09 22:08:39 ohana systemd[1]: Stopped target Local File Systems (Pre).
Oct 09 22:08:39 ohana systemd[1]: Stopping Remount Root and Kernel File Systems...
Oct 09 22:08:39 ohana systemd[1]: Stopped Remount Root and Kernel File Systems.
Oct 09 22:08:39 ohana systemd[1]: Starting Shutdown.
Oct 09 22:08:39 ohana systemd[1]: Reached target Shutdown.
Oct 09 22:08:43 ohana systemd-cryptsetup[11745]: Failed to deactivate: Device or resource busy
Oct 09 22:08:43 ohana systemd[1]: systemd-cryptsetup@crypt\x2dhome.service: control process exited, code=exited status=1
Oct 09 22:08:43 ohana systemd[1]: Stopped Cryptography Setup for crypt-home.
Oct 09 22:08:43 ohana systemd[1]: Unit systemd-cryptsetup@crypt\x2dhome.service entered failed state.
Oct 09 22:08:43 ohana systemd-cryptsetup[11746]: Failed to deactivate: Device or resource busy
Oct 09 22:08:43 ohana systemd[1]: systemd-cryptsetup@crypt\x2dlinux.service: control process exited, code=exited status=1
Oct 09 22:08:43 ohana systemd[1]: Stopped Cryptography Setup for crypt-linux.
Oct 09 22:08:43 ohana systemd[1]: Unit systemd-cryptsetup@crypt\x2dlinux.service entered failed state.
Oct 09 22:08:43 ohana systemd[1]: Starting Unmount All Filesystems.
Oct 09 22:08:43 ohana systemd[1]: Reached target Unmount All Filesystems.

/etc/fstab

# 
# /etc/fstab: static file system information
#
# <file system>	<dir>	<type>	<options>	<dump>	<pass>

# /dev/mapper/linux-root LABEL=root
UUID=a775624b-d31d-40ef-bdd3-60b6d68e8122	/         	ext4      	rw,relatime,data=ordered	0 1

# /dev/sda1 LABEL=boot
UUID=2c2a3ea6-c04d-4e97-b12e-c3a0fc2ab57e	/boot     	ext4      	rw,relatime,data=ordered	0 2

# /dev/mapper/linux-tmp LABEL=tmp
UUID=eab913b9-4df2-4ee4-81ee-21de6f5704e6	/tmp      	ext4      	rw,relatime,data=ordered	0 2

# /dev/mapper/linux-var LABEL=var
UUID=4e1d1868-8b5c-49a6-9120-6eba391a6439	/var      	ext4      	rw,relatime,data=ordered	0 2

# /dev/mapper/linux-storage LABEL=storage
UUID=e4dfa180-acdb-4295-901c-f7d81af1014c	/storage  	ext4      	rw,relatime,data=ordered	0 2

# /dev/mapper/crypt-home
UUID=98691163-fffa-4321-984c-3ba237083524	/home     	ext4      	rw,relatime,data=ordered	0 2

# /dev/mapper/linux-swap
UUID=f8b1e59e-9804-44f0-af79-66810ee49206	none      	swap      	defaults  	0 0

HOOKS from /etc/mkinitcpio.conf

HOOKS="base udev autodetect modconf block keyboard keymap encrypt lvm2 filesystems fsck usr shutdown"

My /etc/crypttab uses a keyfile as well, much like gegenschall's.

If I make sure that LightDM is stopped and the only active login is my user on a tty, I can cd to /, use lsof to make sure that nothing is open in /home, and issue a systemctl poweroff/reboot, the problem seems to go away. Only tried that once, though.

cfr · 2013-10-11 23:20:52

@aoba,
Why is /tmp on disk at all?
Why do you have the usr hook?

@OP,
I would put the shutdown hook last. (I know that works.)

aoba · 2013-10-11 23:45:49

Regarding /tmp - because that is where I want it.

Regarding the usr hook - this is (possibly?) an artifact from trying to troubleshoot the problem described here: Systemd error when using separate /var partition. I am not 100% sure about that. Anyway, I never removed it because having it never broke anything. I will remove it to see if it has any effect on this issue.

Edit: it did not.

Last edited by aoba (2013-10-11 23:57:03)

cfr · 2013-10-12 00:05:00

You don't need the usr hook to have a separate /var partition, for sure.

Have you masked systemd's creation of /tmp as tmpfs? I believe fstab should override but masking it would ensure that.

aoba · 2013-10-12 00:23:09

I have not masked anything, but

# systemctl status tmp.mount

reports the following:

tmp.mount - /tmp
   Loaded: loaded (/etc/fstab; static)
   Active: active (mounted) since Fri 2013-10-11 16:54:27 PDT; 19min ago
    Where: /tmp
     What: /dev/mapper/linux-tmp
  Process: 370 ExecMount=/bin/mount /dev/disk/by-uuid/eab913b9-4df2-4ee4-81ee-21de6f5704e6 /tmp -t ext4 -o rw,relatime,data=ordered (code=exited, status=0/SUCCESS)

Oct 11 16:54:27 ohana systemd[1]: Mounted /tmp.

So I should not need to mask it, correct?

Strike0 · 2013-10-12 11:23:16

That /tmp looks ok to me as well, yes.

@Gegenschall: Please post your HOOK line after you made the change, cfr suggested. Also mkinitcpio has kernel options like "rd.log" which might help troubleshooting, have a look at the manpage. Additionally, you have an error in crypttab. The option is "allow-discards" there.

gegenschall · 2013-10-12 16:35:22

This is my HOOKS array:

HOOKS="base udev autodetect modconf block keymap encrypt filesystems keyboard fsck shutdown"

crypttab(5) says its "discard", not "allow-discard".

Will check out the rd.log parameter later...

aoba · 2013-10-12 20:24:54

I think the /home part of the issue for me is at least partially due to how I have mpd configured. I start it with my X session and it persists after I log out, keeping a few files in my home folder open. If I make sure it is not running, log out to LightDM, and use its menu to reboot, I do not get a journal message about /home. If I kill mpd, but instead issue a `systemctl reboot/poweroff` command from a terminal in X, the problem returns. Is this normal? I guess I expected everything to be automatically cleaned up.

/tmp, on the other hand, remains a mystery. If I remove it from my /etc/fstab - to use the default tmp.mount (tmpfs) systemd provides - the problem goes away. But if I keep it as is, and do something silly like replace /bin/umount with this:

#!/bin/sh

/bin/test "$1" = "/tmp" && /bin/date -Ins >> /umount-tmp.log
/bin/test "$1" = "/tmp" && /bin/lsof /tmp >> /umount-tmp.log

/bin/umount.real "$@"

all I get is a list of times.

Also, I tried following the steps here (Shutdown Completes Eventually), but the output mostly mirrors what I get from journalctl:

[  219.132058] systemd[1]: Stopping Local File Systems.
[  219.132062] systemd[1]: local-fs.target changed active -> dead
[  219.132066] systemd[1]: Job local-fs.target/stop finished, result=done
[  219.132091] systemd[1]: Stopped target Local File Systems.
[  219.132103] systemd[1]: Unmounting /home...
[  219.132136] systemd[1]: About to execute: /bin/umount /home
[  219.132329] systemd[1]: Forked /bin/umount as 908
[  219.132402] systemd[1]: home.mount changed mounted -> unmounting
[  219.132427] systemd[1]: Unmounting /storage...
[  219.132480] systemd[1]: About to execute: /bin/umount /storage
[  219.132735] systemd[1]: Forked /bin/umount as 909
[  219.132805] systemd[1]: storage.mount changed mounted -> unmounting
[  219.132825] systemd[1]: Unmounting /tmp...
[  219.132872] systemd[1]: About to execute: /bin/umount /tmp
[  219.133047] systemd[1]: Forked /bin/umount as 910
[  219.133109] systemd[1]: tmp.mount changed mounted -> unmounting
[  219.133136] systemd[1]: Unmounting /boot...
[  219.133190] systemd[1]: About to execute: /bin/umount /boot
[  219.133355] systemd[909]: Executing: /bin/umount /storage
[  219.133388] systemd[1]: Forked /bin/umount as 911
[  219.133452] systemd[1]: boot.mount changed mounted -> unmounting
[  219.133676] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.134256] systemd[906]: Executing: /usr/lib/systemd/systemd-random-seed save
[  219.134550] systemd[908]: Executing: /bin/umount /home
[  219.135143] systemd[1]: Received SIGCHLD from PID 906 (systemd-random-).
[  219.135170] systemd[1]: Got SIGCHLD for process 906 (systemd-random-)
[  219.135222] systemd[1]: Child 906 died (code=exited, status=0/SUCCESS)
[  219.135226] systemd[1]: Child 906 belongs to systemd-random-seed.service
[  219.135235] systemd[1]: systemd-random-seed.service: control process exited, code=exited status=0
[  219.135292] systemd[907]: Executing: /sbin/swapoff /dev/dm-2
[  219.135462] systemd[910]: Executing: /bin/umount /tmp
[  219.135487] systemd[1]: systemd-random-seed.service got final SIGCHLD for state stop
[  219.135528] systemd[1]: systemd-random-seed.service changed stop -> dead
[  219.135582] systemd[911]: Executing: /bin/umount /boot
[  219.135622] systemd[1]: Job systemd-random-seed.service/stop finished, result=done
[  219.135666] systemd[1]: Stopped Load/Save Random Seed.
[  219.135695] systemd[1]: Unmounting /var...
[  219.135730] systemd[1]: About to execute: /bin/umount /var
[  219.135974] systemd[1]: Forked /bin/umount as 914
[  219.136050] systemd[1]: var.mount changed mounted -> unmounting
[  219.136290] systemd[1]: Accepted connection on private bus.
[  219.136332] systemd[1]: Accepted connection on private bus.
[  219.136529] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.136584] systemd[914]: Executing: /bin/umount /var
[  219.136890] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.137193] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.137222] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.175076] systemd[1]: Received SIGCHLD from PID 754 (sudo).
[  219.175102] systemd[1]: Got SIGCHLD for process 754 (sudo)
[  219.175155] systemd[1]: Child 754 died (code=exited, status=129/n/a)
[  219.200239] systemd[1]: Received SIGCHLD from PID 910 (umount).
[  219.200267] systemd[1]: Got SIGCHLD for process 908 (umount)
[  219.200338] systemd[1]: Child 908 died (code=exited, status=32/n/a)
[  219.200342] systemd[1]: Child 908 belongs to home.mount
[  219.200347] systemd[1]: home.mount mount process exited, code=exited status=32
[  219.200357] systemd[1]: home.mount changed unmounting -> mounted
[  219.200362] systemd[1]: Job home.mount/stop finished, result=failed
[  219.200407] systemd[1]: Failed unmounting /home.
[  219.200454] systemd[1]: Got SIGCHLD for process 910 (umount)
[  219.200524] systemd[1]: Child 910 died (code=exited, status=32/n/a)
[  219.200527] systemd[1]: Child 910 belongs to tmp.mount
[  219.200532] systemd[1]: tmp.mount mount process exited, code=exited status=32
[  219.200540] systemd[1]: tmp.mount changed unmounting -> mounted
[  219.200544] systemd[1]: Job tmp.mount/stop finished, result=failed
[  219.200571] systemd[1]: Failed unmounting /tmp.
[  219.200607] systemd[1]: Got SIGCHLD for process 914 (umount)
[  219.200666] systemd[1]: Child 914 died (code=exited, status=32/n/a)
[  219.200669] systemd[1]: Child 914 belongs to var.mount
[  219.200673] systemd[1]: var.mount mount process exited, code=exited status=32
[  219.200681] systemd[1]: var.mount changed unmounting -> mounted
[  219.200685] systemd[1]: Job var.mount/stop finished, result=failed
[  219.200711] systemd[1]: Failed unmounting /var.
[  219.200737] systemd[1]: Stopping File System Check on /dev/disk/by-uuid/98691163-fffa-4321-984c-3ba237083524...
[  219.200763] systemd[1]: systemd-fsck@dev-disk-by\x2duuid-98691163\x2dfffa\x2d4321\x2d984c\x2d3ba237083524.service changed exited -> dead
[  219.200769] systemd[1]: Job systemd-fsck@dev-disk-by\x2duuid-98691163\x2dfffa\x2d4321\x2d984c\x2d3ba237083524.service/stop finished, result=done
[  219.200797] systemd[1]: Stopped File System Check on /dev/disk/by-uuid/98691163-fffa-4321-984c-3ba237083524.
[  219.200816] systemd[1]: Redirecting stop request from dev-disk-by\x2duuid-98691163\x2dfffa\x2d4321\x2d984c\x2d3ba237083524.device to sys-devices-virtual-block-dm\x2d6.device.
[  219.200823] systemd[1]: Stopping /sys/devices/virtual/block/dm-6.
[  219.200876] systemd[1]: Accepted connection on private bus.
[  219.201099] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.201186] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.201483] systemd[1]: Accepted connection on private bus.
[  219.201642] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.201716] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.204043] systemd[1]: Accepted connection on private bus.
[  219.204142] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.204219] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.234497] systemd[1]: dev-mapper-linux\x2dswap.swap changed active -> dead
[  219.234606] systemd[1]: Job dev-mapper-linux\x2dswap.swap/stop finished, result=done
[  219.234657] systemd[1]: Deactivated swap /dev/mapper/linux-swap.
[  219.234674] systemd[1]: dev-linux-swap.swap changed active -> dead
[  219.234751] systemd[1]: Job dev-linux-swap.swap/stop finished, result=done
[  219.234805] systemd[1]: Deactivated swap /dev/linux/swap.
[  219.234815] systemd[1]: dev-disk-by\x2did-dm\x2duuid\x2dLVM\x2dDevEGGWf3oc8GE2g06c6XaLVUQEgo9cTTSwqNIhBSQfWKqAKYdL5kKqo0rCZ38xZ.swap changed active -> dead
[  219.234970] systemd[1]: Job dev-disk-by\x2did-dm\x2duuid\x2dLVM\x2dDevEGGWf3oc8GE2g06c6XaLVUQEgo9cTTSwqNIhBSQfWKqAKYdL5kKqo0rCZ38xZ.swap/stop finished, result=done
[  219.235007] systemd[1]: Deactivated swap /dev/disk/by-id/dm-uuid-LVM-DevEGGWf3oc8GE2g06c6XaLVUQEgo9cTTSwqNIhBSQfWKqAKYdL5kKqo0rCZ38xZ.
[  219.235017] systemd[1]: dev-disk-by\x2did-dm\x2dname\x2dlinux\x2dswap.swap changed active -> dead
[  219.235097] systemd[1]: Job dev-disk-by\x2did-dm\x2dname\x2dlinux\x2dswap.swap/stop finished, result=done
[  219.235126] systemd[1]: Deactivated swap /dev/disk/by-id/dm-name-linux-swap.
[  219.235135] systemd[1]: dev-disk-by\x2duuid-f8b1e59e\x2d9804\x2d44f0\x2daf79\x2d66810ee49206.swap changed active -> dead
[  219.235214] systemd[1]: Job dev-disk-by\x2duuid-f8b1e59e\x2d9804\x2d44f0\x2daf79\x2d66810ee49206.swap/stop finished, result=done
[  219.235244] systemd[1]: Deactivated swap /dev/disk/by-uuid/f8b1e59e-9804-44f0-af79-66810ee49206.
[  219.235297] systemd[1]: Received SIGCHLD from PID 907 (swapoff).
[  219.235323] systemd[1]: Got SIGCHLD for process 907 (swapoff)
[  219.235390] systemd[1]: Child 907 died (code=exited, status=0/SUCCESS)
[  219.235394] systemd[1]: Child 907 belongs to dev-dm\x2d2.swap
[  219.235399] systemd[1]: dev-dm\x2d2.swap swap process exited, code=exited status=0
[  219.235410] systemd[1]: dev-dm\x2d2.swap changed deactivating -> dead
[  219.235956] systemd[1]: Job dev-dm\x2d2.swap/stop finished, result=done
[  219.236044] systemd[1]: Deactivated swap /dev/dm-2.
[  219.236131] systemd[1]: Got SIGCHLD for process 911 (umount)
[  219.236192] systemd[1]: Child 911 died (code=exited, status=0/SUCCESS)
[  219.236196] systemd[1]: Child 911 belongs to boot.mount
[  219.236201] systemd[1]: boot.mount mount process exited, code=exited status=0
[  219.236210] systemd[1]: boot.mount changed unmounting -> dead
[  219.236294] systemd[1]: Job boot.mount/stop finished, result=done
[  219.236322] systemd[1]: Unmounted /boot.
[  219.236360] systemd[1]: Received SIGCHLD from PID 911 (n/a).
[  219.236413] systemd[1]: Accepted connection on private bus.
[  219.236551] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.237196] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.237321] systemd[1]: Accepted connection on private bus.
[  219.237463] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.237814] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.238324] systemd[1]: Received SIGCHLD from PID 909 (umount).
[  219.238348] systemd[1]: Got SIGCHLD for process 909 (umount)
[  219.238404] systemd[1]: Child 909 died (code=exited, status=0/SUCCESS)
[  219.238407] systemd[1]: Child 909 belongs to storage.mount
[  219.238412] systemd[1]: storage.mount mount process exited, code=exited status=0
[  219.238420] systemd[1]: storage.mount changed unmounting -> dead
[  219.238509] systemd[1]: Job storage.mount/stop finished, result=done
[  219.238540] systemd[1]: Unmounted /storage.
[  219.238556] systemd[1]: Stopping Local File Systems (Pre).
[  219.238562] systemd[1]: local-fs-pre.target changed active -> dead
[  219.238566] systemd[1]: Job local-fs-pre.target/stop finished, result=done
[  219.238592] systemd[1]: Stopped target Local File Systems (Pre).
[  219.238604] systemd[1]: Stopping Remount Root and Kernel File Systems...
[  219.238627] systemd[1]: systemd-remount-fs.service changed exited -> dead
[  219.238631] systemd[1]: Job systemd-remount-fs.service/stop finished, result=done
[  219.238656] systemd[1]: Stopped Remount Root and Kernel File Systems.
[  219.238673] systemd[1]: Starting Shutdown.
[  219.238676] systemd[1]: shutdown.target changed dead -> active
[  219.238679] systemd[1]: Job shutdown.target/start finished, result=done
[  219.238703] systemd[1]: Reached target Shutdown.
[  219.239263] systemd[1]: Accepted connection on private bus.
[  219.239382] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.239752] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  219.630816] systemd[1]: Received SIGCHLD from PID 486 (at-spi-bus-laun).
[  219.630840] systemd[1]: Got SIGCHLD for process 486 (at-spi-bus-laun)
[  219.630896] systemd[1]: Child 486 died (code=exited, status=0/SUCCESS)
[  219.668697] systemd[1]: Received SIGCHLD from PID 449 (X).
[  219.668725] systemd[1]: Got SIGCHLD for process 449 (X)
[  219.668781] systemd[1]: Child 449 died (code=exited, status=0/SUCCESS)
[  219.669379] systemd[1]: Accepted connection on private bus.
[  219.669545] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  219.669606] systemd[1]: lightdm.service: cgroup is empty
[  219.669636] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  220.420041] systemd[1]: Received SIGCHLD from PID 845 (sleep).
[  220.420064] systemd[1]: Got SIGCHLD for process 845 (sleep)
[  220.420103] systemd[1]: Child 845 died (code=exited, status=0/SUCCESS)
[  221.914117] systemd[1]: Received SIGCHLD from PID 545 (dbus-launch).
[  221.914141] systemd[1]: Got SIGCHLD for process 545 (dbus-launch)
[  221.914184] systemd[1]: Child 545 died (code=exited, status=0/SUCCESS)
[  221.914458] systemd[1]: Received SIGCHLD from PID 483 (dbus-launch).
[  221.914486] systemd[1]: Got SIGCHLD for process 483 (dbus-launch)
[  221.914529] systemd[1]: Child 483 died (code=exited, status=0/SUCCESS)
[  221.915102] systemd[1]: Accepted connection on private bus.
[  221.915222] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  221.915328] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  223.957616] systemd[1]: Received SIGCHLD from PID 904 (systemd-cryptse).
[  223.957639] systemd[1]: Got SIGCHLD for process 904 (systemd-cryptse)
[  223.957707] systemd[1]: Child 904 died (code=exited, status=1/FAILURE)
[  223.957712] systemd[1]: Child 904 belongs to systemd-cryptsetup@crypt\x2dhome.service
[  223.957720] systemd[1]: systemd-cryptsetup@crypt\x2dhome.service: control process exited, code=exited status=1
[  223.957782] systemd[1]: systemd-cryptsetup@crypt\x2dhome.service got final SIGCHLD for state stop
[  223.957818] systemd[1]: systemd-cryptsetup@crypt\x2dhome.service changed stop -> failed
[  223.957904] systemd[1]: Job systemd-cryptsetup@crypt\x2dhome.service/stop finished, result=done
[  223.957917] systemd[1]: Stopped Cryptography Setup for crypt-home.
[  223.957928] systemd[1]: Unit systemd-cryptsetup@crypt\x2dhome.service entered failed state.
[  223.958243] systemd[1]: Accepted connection on private bus.
[  223.958397] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  223.958509] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  224.016365] systemd[1]: Received SIGCHLD from PID 905 (systemd-cryptse).
[  224.016390] systemd[1]: Got SIGCHLD for process 905 (systemd-cryptse)
[  224.016447] systemd[1]: Child 905 died (code=exited, status=1/FAILURE)
[  224.016451] systemd[1]: Child 905 belongs to systemd-cryptsetup@crypt\x2dlinux.service
[  224.016457] systemd[1]: systemd-cryptsetup@crypt\x2dlinux.service: control process exited, code=exited status=1
[  224.016529] systemd[1]: systemd-cryptsetup@crypt\x2dlinux.service got final SIGCHLD for state stop
[  224.016565] systemd[1]: systemd-cryptsetup@crypt\x2dlinux.service changed stop -> failed
[  224.016661] systemd[1]: Job systemd-cryptsetup@crypt\x2dlinux.service/stop finished, result=done
[  224.016676] systemd[1]: Stopped Cryptography Setup for crypt-linux.
[  224.016687] systemd[1]: Unit systemd-cryptsetup@crypt\x2dlinux.service entered failed state.
[  224.016703] systemd[1]: Starting Unmount All Filesystems.
[  224.016707] systemd[1]: umount.target changed dead -> active
[  224.016711] systemd[1]: Job umount.target/start finished, result=done
[  224.016717] systemd[1]: Reached target Unmount All Filesystems.
[  224.016728] systemd[1]: Starting Final Step.
[  224.016731] systemd[1]: final.target changed dead -> active
[  224.016734] systemd[1]: Job final.target/start finished, result=done
[  224.016742] systemd[1]: Reached target Final Step.
[  224.016754] systemd[1]: Starting Reboot...
[  224.016866] systemd[1]: About to execute: /usr/bin/systemctl --force reboot
[  224.017057] systemd[1]: Forked /usr/bin/systemctl as 928
[  224.017193] systemd[1]: systemd-reboot.service changed dead -> start
[  224.018230] systemd[928]: Executing: /usr/bin/systemctl --force reboot
[  224.018328] systemd[1]: Accepted connection on private bus.
[  224.018435] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
[  224.018504] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
[  224.019495] systemd[1]: Accepted connection on private bus.
[  224.019712] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.Reboot() on /org/freedesktop/systemd1
[  224.019734] systemd[1]: Shutting down.
[  224.023022] systemd[1]: Hardware watchdog 'NV_TCO', version 0
[  224.023031] systemd[1]: Failed to set timeout to 600s: Invalid argument
[  224.023033] nv_tco: Unexpected close, not stopping watchdog!
[  225.162099] systemd-journald[215]: Received SIGTERM
[  225.515048] EXT4-fs (dm-6): re-mounted. Opts: (null)
[  225.687382] EXT4-fs (dm-4): re-mounted. Opts: (null)
[  225.796081] EXT4-fs (dm-3): re-mounted. Opts: (null)
[  225.915129] EXT4-fs (dm-1): re-mounted. Opts: (null)
[  225.919881] EXT4-fs (dm-1): re-mounted. Opts: (null)
[  225.919911] EXT4-fs (dm-1): re-mounted. Opts: (null)
[  226.283469] EXT4-fs (dm-1): re-mounted. Opts: data=ordered

Strike0 · 2013-10-12 23:56:14

@Gegenschall: sorry, wrong route for the discard, now both are supported. I missed that they changed it recently so that debian avoids problems with the hyphen
Your HOOK line looks good to me. How about the observation of aoba about mpd? Maybe you have something similar running as well that fails to shutdown in time although it should?

gegenschall · 2013-10-13 16:45:38

edit: I used aoba's method to find out what's running before umount. First I thought it was pulseaudio as the process had some files open just before umount. After several restarts this doesn't hold: It's always another random process having files open. Sometimes zsh, sometimes pulse, or whatnot. I'm not sure what to make of this. Timing issue? I thought systemd tried several times to umount any mountpoint?

@aoba: If you use something like this, you might see something in /umount-tmp.log:

/bin/test "$1" = "/tmp" && fuser -v -m $1 &>> /umount-tmp.log
/bin/test "$1" = "/tmp" && lsof $1 &>> /umount-tmp.log

Last edited by gegenschall (2013-10-13 17:13:45)

aoba · 2013-10-15 20:04:03

It is still unclear to me what the actual problem is here, but in my case I am close to certain that it has something to do with mpd and LightDM. Only two consistent patterns showed up when using my umount wrapper script (with gegenschall's fuser suggestion):

If /tmp fails to unmount, fuser will always blame (at least) an X process.
If mpd is running, /home will fail to unmount.

There were events I still cannot explain: sometimes there were complaints about chromium as well; sometimes /tmp and/or /home unmounted cleanly, etc.

In any case, I decided to try using something other than LightDM, so I replaced it with slim, and - provided I still account for mpd - the problem seems to be gone. It has only been three or four cycles with this setup, so I may come back in a few days with a "never mind", but I thought I should share.

speeddefrost · 2013-12-16 00:24:14

I was having the exact same issue. It was being caused by a bug in infinality (freetype2), which was causing urxvt to segfault and hang after being closed. It wasn't responding to SIGTERM when halting/rebooting either.

Last edited by speeddefrost (2013-12-16 01:05:36)

Strike0 · 2013-12-21 14:21:20

There is a recent new feature to optionally replace the shutdown hook: https://mailman.archlinux.org/pipermail … 25742.html
Obviously it won't fix any applications creating the initial problem, but maybe it makes a difference to some having the issue.

LeCrayonVert · 2013-12-24 09:40:27

aoba wrote:

It is still unclear to me what the actual problem is here, but in my case I am close to certain that it has something to do with mpd and LightDM. Only two consistent patterns showed up when using my umount wrapper script (with gegenschall's fuser suggestion):
If /tmp fails to unmount, fuser will always blame (at least) an X process.
If mpd is running, /home will fail to unmount.
There were events I still cannot explain: sometimes there were complaints about chromium as well; sometimes /tmp and/or /home unmounted cleanly, etc.
In any case, I decided to try using something other than LightDM, so I replaced it with slim, and - provided I still account for mpd - the problem seems to be gone. It has only been three or four cycles with this setup, so I may come back in a few days with a "never mind", but I thought I should share.

Well I've got the exact same issue (though using LVM instead of an encrypted setup) even when I don't login at all (which means this is not caused by MPD directly which I've also tried to kill before shutdown/reboot without any success). I'll try another session manager and keep you informed.
BTW, maybe you should remove the "(encrypted)" part of the post title ?

edit : OK, this is definitely caused by LightDM... I've just switched to gdm-old without changing anything else in my setup... and everything is back to normal...

Last edited by LeCrayonVert (2013-12-24 10:00:24)

teateawhy · 2013-12-24 11:36:27

Better create a bug report about it here:
https://launchpad.net/lightdm

LeCrayonVert · 2013-12-24 13:28:51

Well I'm not quite so sure now... since it does not explain why it was working until today
But I may have a clue about what is going on (at least for me) :
I have a daily cron script using fcron that uses wput to upload some files on a FTP server. And (just a coincidence) yesterday my ISP has just changed the FTP domain name, so this script was just running endlessly. And because of the fcron bootrun option :

bootrun
Run an &-line at fcron's startup if it should have run during system down time.

the script was rerun on the next reboot leaving some opened files.

It might explain why I've still experienced this issue after multiple reboots.
I've added a timeout for all my script that use wput to prevent this from happening again. (wput does not have a timeout parameter)

Arch Linux

#1 2013-10-09 17:15:12

systemd doesn't umount (encrypted) /home and /tmp on shutdown

#2 2013-10-10 01:05:19

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#3 2013-10-10 09:37:40

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#4 2013-10-10 15:18:24

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#5 2013-10-11 11:58:50

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#6 2013-10-11 20:01:20

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#7 2013-10-11 23:20:52

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#8 2013-10-11 23:45:49

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#9 2013-10-12 00:05:00

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#10 2013-10-12 00:23:09

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#11 2013-10-12 11:23:16

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#12 2013-10-12 16:35:22

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#13 2013-10-12 20:24:54

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#14 2013-10-12 23:56:14

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#15 2013-10-13 16:45:38

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#16 2013-10-15 20:04:03

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#17 2013-12-16 00:24:14

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#18 2013-12-21 14:21:20

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#19 2013-12-24 09:40:27

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#20 2013-12-24 11:36:27

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

#21 2013-12-24 13:28:51

Re: systemd doesn't umount (encrypted) /home and /tmp on shutdown

Board footer