XFS journal corruption after every reboot/shutdown

Hi,

the root partition on three different Fedora 27 based machines is XFS-formatted. After every reboot or shutdown, dmesgs shows the following lines after restarting:

[htd@kiera ~]$ dmesg | grep XFS

[    2.773271] SGI XFS with ACLs, security attributes, no debug enabled
[    2.774950] XFS (sda2): Mounting V4 Filesystem
[    2.851266] XFS (sda2): Starting recovery (logdev: internal)
[    2.876522] XFS (sda2): Ending recovery (logdev: internal)

/dev/sda2 is the root partition. /home, which also is XFS formatted, is fine. The journal gets automatically recovered in the boot process and root mounts just fine. But this happens after every single reboot or shutdown - on three different machines with two different kernels (4.14.4 and 4.14.12) and three different harddisks. And it's always and solely the root partition which is affected.

To me, it looks like the root partition doesn't get properly unmounted on reboot or shutdown, but I can not find anything in the logs that is suspicious. I have also looked into systemd sourcecode and the systemd shutdown process, but can not see that the root partition is actually unmounted.

Do you have any advice what to do further, or any hint on what could be happening here? Is this behaviour intended?

I have also filed a bug report here because there's F27 on all machines:
https://bugzilla.redhat.com/show_bug.cgi?id=1533620

Many thanks in advance,
Heinz

That's not corruption - that's normal log recovery running at mount time.

That's because it's not. systemd itself still has open references to the root filesysetm, so when it tries to unmount the root fs, it fails with -EBUSY. So it then remounts the root filesystem read only. It does this with ext3/4 filesystems as well - put a serial console on your machine and just before the machine reboots/powers off you'll see something like this:

[1883430.750756] systemd-shutdown[1]: Unmounting file systems.
[1883430.752130] systemd-shutdown[17403]: Remounting '/' read-only in with options 'seclabel,errors=remount-ro,data=ordered'.
[1883430.856501] EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro,data=ordered
[1883430.908480] systemd-shutdown[1]: All filesystems unmounted.

On XFS, this leaves the journal dirty so that when the filesystem is mounted on boot it can clean up things like orphan inodes that were present at the time of the remount,ro (e.g. open but unlinked files).

IOWs, what you are seeing is normal filesystem behaviour that is a result of systemd being unable to unmount the root filesystem cleanly because it still has references open to the root filesystem.

Not a bug, please close it.

Cheers,

Dave.

Dave Chinner
[email protected]

Or, it's a systemd bug. I switched components, they can decide whether it's their bug. :)

-Eric

Ok, I see. Thanks for clarifying!

I remember a time not too long ago where the root fs was clean after a reboot/shutdown (maybe around F25?). So something must have changed in the way systemd performs a reboot/shutdown..

Thanks,
Heinz

I forget when, but plymouth started exempting itself from being force quit by systemd on shutdown. In my case it was preventing remount ro. I'm not even certain systemd tries to do umount on rootfs if an initramfs is being used, I'm pretty sure it only does remount ro. And in the successful remount ro case, I never see the log replay on XFS at next boot.

You could try to mask the use of plymouth in systemd (or uninstall it). If the problem goes away, that's the culprit. If it doesn't you can probably track down what's holding up the remount ro with
https://freedesktop.org/wiki/Software/systemd/Debugging/#index2h1
And following the "eventually shuts down" section.

Chris Murphy

I removed plymouth a long time ago, because to me it's useless.

And that solved the problem! Not the debugging itself, but the debug script that is mentioned in the text you directed me to. After placing the debug script in /usr/lib/systemd/systemd-shutdown, the root fs is clean after reboot/shutdown:

[htd@chiara ~]$ dmesg | grep XFS

[    2.085668] SGI XFS with ACLs, security attributes, no debug enabled
[    2.086856] XFS (nvme0n1p3): Mounting V5 Filesystem
[    2.093919] XFS (nvme0n1p3): Ending clean mount

Here's the debug script:

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

It simply remounts the root fs rw, dumps the output of dmesg to disk, and remounts the root fs ro afterwards. I tried to find out exactly where and when in the shutdown process this script is executed, but have to admit that my understanding of systemd is not deep enough.

I think something in how systemd performs a reboot/shutdown is wrong. Will add this information to my bug report and hope this rings a bell for the systemd developers.

Thanks a lot,
Heinz