Hello friends,

At work I've been trying to understand an issue where, once in a
thousand or so boots of a Ubuntu Noble based QEMU vm instance, a
non-root, non-boot [email protected] job stops. The systemd-fsck
stoppage prevents a mount from happening.

Our fstabs use filesystem uuids for mounts. I also see the .device unit
corresponding to the /dev/disk/by-uuid symlink for that filesystem in
inactive (dead) state. However, similar reports I'm getting from the
field only have the systemd-fsck service in inactive (dead) state. For
them, the .device unit for the byuuid symlink somehow stays in active
state through the time we look at the machine. I haven't been able to
reproduce it quite like that myself only with the symlink .device unit
also inactive (dead).

I can reproduce my version of it in a QEMU vm using the following new
debugging unit. More realistic field reports have come from real
hardware with nvme and with VMs and come from their normal activities,
but they have many machines or run many tests of other things.

------------------------------------------------------------------------
[Unit]
Description=Reboot if no mounts fail
SuccessAction=reboot
DefaultDependencies=no
Requires=local-fs.target
After=local-fs.target

[Install]
WantedBy=sysinit.target
------------------------------------------------------------------------

With grub.cfg's timeout reduced to 0 seconds, a relatively small
number of packages installed, and five virtual drives I reliably get the
problem within 2.5 hours. With reboots every 7 or 8 seconds that's on
the order of 1000 tries, not unlike the attempts mentioned in Ubuntu bug
2090972, the description of which has other similarities to what I'm
seeing:

https://bugs.launchpad.net/ubuntu/+source/util-linux/+bug/2090972

However, I am running with the Ubuntu patch they felt would solve that
issue. Some among you may remember that patch from this util-linux-ng list
thread:

https://marc.info/?l=util-linux-ng&m=173196251132352&w=2

Here's how things stand when my debug service above stops rebooting,
i.e. when a mount fails to happen (sc below is an eshell alias for
systemctl):

/scp:qvm:~ # lsblk -f
NAME   FSTYPE FSVER LABEL UUID                                 FSAVAIL FSUSE% 
MOUNTPOINTS
sda                                                                           
├─sda1 ext4   1.0         02db5d47-52b2-4dfe-9a4c-79d4191ad2b1    8.2G    12% /
├─sda2 ext4   1.0         442b31f8-aa78-437a-8502-ce3ee216166a    4.7G    14% 
/var
├─sda3 swap   1           9349e686-25e9-4c16-8a7f-993df661a27c                
[SWAP]
├─sda4 ext4   1.0         3a00df39-ae65-45e4-9de2-006236def3c4   27.4G     0% 
/cache
└─sda5 vfat   FAT32       264A-CB3B                             501.4M     0% 
/boot/efi
sdb                                                                           
├─sdb1 ext4   1.0         4a3c4c38-782d-44b4-b4cf-0c01f26b9797   22.2G     0% 
/usr/local/acme
├─sdb2 ext4   1.0         39451f62-cfd7-4c5d-9fa1-f97b1d15c22c    2.7G     0% 
/tmp
└─sdb3 ext4   1.0         5621b9bb-f7c1-4b80-89f6-86971e356555   21.3G     0% 
/cache2
sdc                                                                           
├─sdc1 ext4   1.0         21c1eca1-d0db-4cbb-8535-172f4e013a01   40.8G     0% 
/cache3
└─sdc2 ext4   1.0         a4a60745-1f2d-4008-96fa-28822d2ee551    5.5G     0% 
/usr/local/acme/coredumps
sdd                                                                           
├─sdd1 ext4   1.0         d181e1ba-b9fe-4d0f-bf87-73332fca2d6e   29.7G     0% 
/cache4
└─sdd2 ext4   1.0         44ab0ceb-8545-473a-a02b-ffc6596c2f6d   16.5G     1% 
/usr/local/acme/logs
sde                                                                           
└─sde1

(sde1 failed to mount at on /cache5)

/scp:qvm:~ # sc list-dependencies --all cache5.mount
cache5.mount
● ├─-.mount
● │ └─-.slice
○ ├─dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.device
● ├─system.slice
● │ └─-.slice
○ 
└─systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service
○   
├─dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.device
●   ├─system-systemd\x2dfsck.slice
●   │ └─system.slice
●   │   └─-.slice
●   └─systemd-fsckd.socket
●     ├─-.mount
●     │ └─-.slice
●     └─system.slice
●       └─-.slice

/scp:qvm:~ # sc status 
'dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.device'
○ dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.device - 
QEMU_HARDDISK primary
     Loaded: loaded
     Active: inactive (dead) since Wed 2026-06-10 18:22:59 UTC; 1h 39min ago
   Duration: 686ms

Notice: journal has been rotated since unit was started, output may be 
incomplete.

# that symlink is missing -- it's in the fstab, though...
/scp:qvm:~ # *ls -l /dev/disk/by-uuid/
total 0
lrwxrwxrwx 1 root root 10 Jun 10 18:22 02db5d47-52b2-4dfe-9a4c-79d4191ad2b1 -> 
../../sda1
lrwxrwxrwx 1 root root 10 Jun 10 18:22 21c1eca1-d0db-4cbb-8535-172f4e013a01 -> 
../../sdc1
lrwxrwxrwx 1 root root 10 Jun 10 18:22 264A-CB3B -> ../../sda5
lrwxrwxrwx 1 root root 10 Jun 10 18:22 39451f62-cfd7-4c5d-9fa1-f97b1d15c22c -> 
../../sdb2
lrwxrwxrwx 1 root root 10 Jun 10 18:22 3a00df39-ae65-45e4-9de2-006236def3c4 -> 
../../sda4
lrwxrwxrwx 1 root root 10 Jun 10 18:22 442b31f8-aa78-437a-8502-ce3ee216166a -> 
../../sda2
lrwxrwxrwx 1 root root 10 Jun 10 18:22 44ab0ceb-8545-473a-a02b-ffc6596c2f6d -> 
../../sdd2
lrwxrwxrwx 1 root root 10 Jun 10 18:22 4a3c4c38-782d-44b4-b4cf-0c01f26b9797 -> 
../../sdb1
lrwxrwxrwx 1 root root 10 Jun 10 18:22 5621b9bb-f7c1-4b80-89f6-86971e356555 -> 
../../sdb3
lrwxrwxrwx 1 root root 10 Jun 10 18:22 9349e686-25e9-4c16-8a7f-993df661a27c -> 
../../sda3
lrwxrwxrwx 1 root root 10 Jun 10 18:22 a4a60745-1f2d-4008-96fa-28822d2ee551 -> 
../../sdc2
lrwxrwxrwx 1 root root 10 Jun 10 18:22 d181e1ba-b9fe-4d0f-bf87-73332fca2d6e -> 
../../sdd1

/scp:qvm:~ [3] # sc status -l 
'systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service'
○ 
systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service
 - File System Check on /dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012
     Loaded: loaded (/usr/lib/systemd/system/[email protected]; static)
     Active: inactive (dead) since Wed 2026-06-10 18:22:59 UTC; 1h 43min ago
   Duration: 220ms
       Docs: man:[email protected](8)
    Process: 1707 ExecStart=/usr/lib/systemd/systemd-fsck 
/dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012 (code=exited, 
status=0/SUCCESS)
   Main PID: 1707 (code=exited, status=0/SUCCESS)
        CPU: 7ms

Jun 10 18:22:59 a192-168-100-2.deploy.acmetechnologies.com systemd[1]: Starting 
systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service
 - File System Check on 
/dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012...
Jun 10 18:22:59 a192-168-100-2.deploy.acmetechnologies.com systemd-fsck[1737]: 
/dev/sde1: clean, 11/3276800 files, 284558/13106176 blocks
Jun 10 18:22:59 a192-168-100-2.deploy.acmetechnologies.com systemd[1]: Finished 
systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service
 - File System Check on /dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012.
Jun 10 18:22:59 a192-168-100-2.deploy.acmetechnologies.com systemd[1]: 
systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service:
 Deactivated successfully.
Jun 10 18:22:59 a192-168-100-2.deploy.acmetechnologies.com systemd[1]: Stopped 
systemd-fsck@dev-disk-by\x2duuid-a541cf1a\x2d096d\x2d4f5d\x2db431\x2d93ce3440c012.service
 - File System Check on /dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012.
/scp:qvm:~ [3] # sc status -l 'cache5.mount'
○ cache5.mount - /cache5
     Loaded: loaded (/etc/fstab; generated)
     Active: inactive (dead)
      Where: /cache5
       What: /dev/disk/by-uuid/a541cf1a-096d-4f5d-b431-93ce3440c012
       Docs: man:fstab(5)
             man:systemd-fstab-generator(8)

The filesystem that doesn't mount varies across runs, but I've only seen
non-root, non-boot filesystems fail this way. I have seen it both for
top level mounts (like /cache5) and for nested ones (like
/usr/local/acme/logs, where /usr/local/acme is one mountpoint and
.../logs a second on from that filesystem). It's very easy to perturb
this problem away by running with more or different software installed.
It seems not to happen in Ubuntu 22.04 only 24.04 for me. I've only
tried those two. Our company does have some patches to each, including
some to Ubuntu's util-linux and systemd packages, but nothing that I
think would be relevant (see below about locking problems).

This run of udevd is after pivot to root when systemd is starting for
the first time.  There would be an earlier run of udevd, but not of
systemd, when our initramfs scripts ran.

I attempted some printf debugging and noticed a couple things:

1. a by-uuid symlink does not come out of a call to built_blkid() in
udev-builtin-blkid.c from a (post root pivot) udevd worker tasked with
handling an add uevent for the block device of my missing mount. That
while processing this line from 60-persistent-storage.rules.

KERNEL!="sr*|mmcblk[0-9]boot[0-9]", IMPORT{builtin}="blkid"

2. Then when the same udev worker gets to the following line from
60-persistent-storage.rules, ENV{ID_FS_UUID_ENC} is empty and the code
to add that devlink to the event dev structures list of devlinks never
does so, never has anything to add. Later in udev_event_execute_rules()
there is a call to update_devnode() which calls udev_node_update(dev,
dev_old) where the dev (the event's dev struct) lacks the devlink and
the dev_old (a memory representation of initramfs phase's left of udev
db?) has the devlink. From that discrepancy the worker gets into
udev_node_update() and issues the message, "Removing/updating old device
symlink '%s', which is no longer belonging to this device." Then
link_update() issues the message "No reference left for '%s', removing".

The rules line for all of that:
ENV{ID_FS_USAGE}=="filesystem|other|crypto", ENV{ID_FS_UUID_ENC}=="?*", 
SYMLINK+="disk/by-uuid/$env{ID_FS_UUID_ENC}"

I think that the symlink must have existed after the earlier udevd run
with that event that would have happened in the initramfs phase but is
now being removed in the post root pivot phase. (I haven't set up
debugging visibility into the initramfs phase.) However, I have to admit
my debugging of that got a bit confused. I see that unlink did not give
ENOENT, so I guess it existed, but at the same time I tried adding an
IMPORT{PROGRAM} udev rule in an earlier line in
60-persistent-storage.rules to call a script to write the listing of
/dev/by-uuid and that seemed to show the link already missing before the
SYMLINK+= line above. I'm hoping that's not important, that maybe the
file created by that import{program} script was actually written again
in a later rule processing run after the link had been removed, but I
haven't yet cleared up this point to my own satisfaction.

So far I have not debugged into libblkid to see exactly how it fails to
give out the by-uuid symlink. But I've found two patches that have me thinking 
maybe I should write you
now before continuing my debugging.

The first was Ubuntu bug 2090972 and the corresponding patch, named
lp2090972-libblkid-fix-spurious-ext-superblock-checksum-mismat.patch in
2.39.3-9ubuntu6.4. I'm running with that patch and it is not helping me.

The second is this freedesktop bug report that culminated in Karol Zak
changing the flock that util-linux's fsck used to take on
/dev/<diskname> to /run/fsck/<diskname>.lock:

https://bugs.freedesktop.org/show_bug.cgi?__goaway_challenge=resource-load&__goaway_id=e2d761e9cfa8d2efdfbb2c282f93b508&id=79576

Change:

https://github.com/karelzak/util-linux/commit/3bbdae633f4a1dda5f95ee6c61f18a1c8ef12250

I wonder about that patch. When a udev worker starts processing an event
on a block device it takes a shared flock on the disk node, e.g.
/dev/sdc. Before 2014, when fsck took the exclusive flock on /dev/sdc in
preparation for writing the superblock (with fields like "Last write
time" or "Checksum") that would have avoided libblkid looking in there
while fsck was writing. With fsck now taking an exclusive flock on
/run/fsck/sdc.lock instead there's no such protection.

I notice correspondence in the second of the last write time and the
udev rule processing not getting a by-uuid symlink/devlink in my
failures (different run from earlier):

dumpe2fs 1.47.0 (5-Feb-2023)
...
Filesystem created:       Thu Jul  2 16:40:07 2026
Last mount time:          Thu Jul  2 19:05:56 2026
Last write time:          Thu Jul  2 19:06:03 2026
...

(I added some of these debugging messages in a custom version of udevd)

Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: '/lib/udev/vdev_id -d sdc2'(out) 'Error: Config file 
"/etc/zfs/vdev_id.conf" not found'
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Process '/lib/udev/vdev_id -d sdc2' failed with exit 
code 1.
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: /usr/lib/udev/rules.d/69-vdev.rules:6 Command 
"/lib/udev/vdev_id -d sdc2" returned 1 (error), ignoring
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Setting permissions /dev/sdc2, uid=0, gid=6, 
mode=0660
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Removing/updating old device symlink 
'/dev/disk/by-uuid/c9239fff-20aa-4ef9-a241-1451ca441c2b', which is no longer 
belonging to this device.
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Links that do belong to this device...
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 
------------------------------------------------------------------------
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 0: /dev/disk/by-id/scsi-0QEMU_QEMU_HARDDISK_3-part2
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 1: 
/dev/disk/by-partuuid/c35ef30e-027f-4ea5-b88d-db0752ae06b3
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 2: /dev/disk/by-diskseq/27-part2
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 3: 
/dev/disk/by-path/pci-0000:00:03.0-scsi-0:0:2:0-part2
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 4: /dev/disk/by-partlabel/primary
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: 
------------------------------------------------------------------------
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: No reference left for 
'/dev/disk/by-uuid/c9239fff-20aa-4ef9-a241-1451ca441c2b', removing
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Successfully created symlink 
'/dev/disk/by-diskseq/27-part2' to '/dev/sdc2'
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Successfully created symlink 
'/dev/disk/by-partlabel/primary' to '/dev/sdc2'
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Successfully created symlink '/dev/block/8:34' to 
'/dev/sdc2'
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: sd-device: Created db file '/run/udev/data/b8:34' 
for 
'/devices/pci0000:00/0000:00:03.0/virtio0/host2/target2:0:2/2:0:2:0/block/sdc/sdc2'
Jul 02 19:06:03 a192-168-100-2.deploy.akamaitechnologies.com 
(udev-worker)[1603]: sdc2: Adding watch on '/dev/sdc2'
Jul 02 19:06:03 
a192-168-100-2.deploy.akamaitechnologies.com(udev-worker)[1603]: sdc2: Device 
processed (SEQNUM=2471, ACTION=add)

As an experiment I added a shared flock on /run/fsck/<uevent drive>.lock
to the TK_M_IMPORT_BUILTIN case of the switch in
udev_rule_apply_token_to_event(). I narrowed it so it would only
activate for a line I care about in the udev rules file, since it's very
easy to perturb this bug away with timing changes, particularly
debugging messages (and maybe checksum checks and retries to read the
superblock if that's not too flippant to write here?). When I used a
blocking flock call, I stopped seeing the problem (up to 7 hours trying
instead of 2.5). If I instead used a non-blocking flock and reported the
EAGAIN/EWOULDBLOCK as a log message while allowing rule processing to
carry on, I got the failure as usual accompanied by a log message saying
flock failed with errno=11 (EAGAIN/EWOULDBLOCK). That bears out what I'm
saying about the util-linux choice of lock file needing to go back to
what it was, I think. Or at least that's what I thought I'd suggest to
my boss for how we'd patch our copy.

However, I didn't really understand well that freedesktop bug report
from 2014 (bug 79576). If Karol reverted util-linux commit
3bbdae633f4a1d would that cause other problems? It looks to me like if
udevd doesn't get its shared flock it would just put that event back in
its queue and try again later. But that didn't work in 2014?

(Sorry, this is awfully long, but I didn't know what to leave out.)

Regards,
Mike Small

Reply via email to