Bug 1860602 - sometimes fstab references a /dev node instead of fs UUID
Summary: sometimes fstab references a /dev node instead of fs UUID
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: python-blivet
Version: 34
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Vojtech Trefny
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1876261 (view as bug list)
Depends On:
Blocks: 1851166
TreeView+ depends on / blocked
 
Reported: 2020-07-25 15:59 UTC by Chris Murphy
Modified: 2021-05-10 05:55 UTC (History)
15 users (show)

Fixed In Version: python-blivet-3.4.0-1.fc35
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-05-07 15:43:17 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
fstab (583 bytes, text/plain)
2020-07-25 16:03 UTC, Chris Murphy
no flags Details
anaconda.log (58.25 KB, text/plain)
2020-07-25 16:03 UTC, Chris Murphy
no flags Details
storage.log (811.89 KB, text/plain)
2020-07-25 16:04 UTC, Chris Murphy
no flags Details
program.log (6.44 KB, text/plain)
2020-07-25 16:04 UTC, Chris Murphy
no flags Details
fstab - f34 (666 bytes, text/plain)
2021-02-14 07:23 UTC, Chris Murphy
no flags Details
program.log - f34 (16.17 KB, text/plain)
2021-02-14 07:24 UTC, Chris Murphy
no flags Details
storage.log - f34 (445.08 KB, text/plain)
2021-02-14 07:24 UTC, Chris Murphy
no flags Details
anaconda.log - f34 (32.34 KB, text/plain)
2021-02-14 07:25 UTC, Chris Murphy
no flags Details
storage.state (24.00 KB, application/octet-stream)
2021-02-14 07:26 UTC, Chris Murphy
no flags Details
journalctl out (2.31 MB, text/plain)
2021-02-14 07:26 UTC, Chris Murphy
no flags Details
another example (237.73 KB, application/gzip)
2021-02-23 17:47 UTC, Chris Murphy
no flags Details
journal.log with udev.log-priority=debug (5.20 MB, text/plain)
2021-02-23 21:28 UTC, Chris Murphy
no flags Details

Description Chris Murphy 2020-07-25 15:59:25 UTC
Description of problem:

Unusual and complicated 3 device setup, but somehow the /etc/fstab ends up with '/dev/vda3' to be mounted at /var instead of by fs UUID. Since there are three devices, there's some chance its node changes and then boot will fail.


Version-Release number of selected component (if applicable):


How reproducible:
Rare, but if you produce such a layout it always happens


Steps to Reproduce:
1. vda: bios boot, /boot, and /var; vdb+vdc / on btrfs raid1
2.
3.

Actual results:

/etc/fstab uses /dev/vda3 for /var instead of by its UUID


Expected results:

/etc/fstab should always use fs UUID instead of device nodes

Additional info:

Comment 1 Chris Murphy 2020-07-25 16:03:36 UTC
Created attachment 1702403 [details]
fstab

Comment 2 Chris Murphy 2020-07-25 16:03:48 UTC
Created attachment 1702404 [details]
anaconda.log

Comment 3 Chris Murphy 2020-07-25 16:04:04 UTC
Created attachment 1702405 [details]
storage.log

Comment 4 Chris Murphy 2020-07-25 16:04:17 UTC
Created attachment 1702406 [details]
program.log

Comment 5 Vladimír Slávik 2020-08-17 16:55:35 UTC
Chris, have you observed this with filesystems other than btrfs for the affected mount point? There is a distinct code path for this with btrfs, as opposed to all other filesystems. So instinctively it seems that would be the broken thing.

Note I'm asking only about possible experience you already had, you don't have to go verify that ;-)

PS: Also, did you make the layout in gui, or via kickstart? Just curious, since gui is currently unusable for your setup due to bug 1828092 I think...

----

Notes to self:

- We get fstab here before writing: https://github.com/rhinstaller/anaconda/blob/master/pyanaconda/modules/storage/devicetree/fsset.py#L767
- The "device" there is a blivet thing. Looking at these device classes:
-- UUID is referenced in StorageDevice and PartitionDevice. There fstab_spec() always checks if self.format.uuid exists, and writes it only if available.
-- For BTRFSDevice, fstab_spec() checks self.format.vol_uuid instead: https://github.com/storaged-project/blivet/blob/3.3-devel/blivet/devices/btrfs.py#L147

Looks like we don't touch vol_uuid anywhere, which might mean either that we should, or that it's a blivet problem instead...

Comment 6 Chris Murphy 2020-08-17 18:16:04 UTC
It's not possible to exactly reproduce the conditions with any other file system. Other file systems don't directly support multiple devices. In the case of btrfs multiple device volume, libblkid reports each member device as having the same btrfs fs UUID. This is expected. But maybe if blivet sees multiple fs uuids, it falls back to picking just one of the device nodes?

Would running anaconda with inst.loglevel=debug reveal more about why it's using /dev node instead of uuid?

Comment 7 Vladimír Slávik 2020-08-19 17:21:20 UTC
Spent some more time with the logs and code. I can't find any traces of this in Anaconda, everything is in blivet. Thus reassigning.

Comment 8 Vojtech Trefny 2020-09-09 06:43:56 UTC
*** Bug 1876261 has been marked as a duplicate of this bug. ***

Comment 9 Chris Murphy 2020-10-05 04:52:08 UTC
python-blivet-3.3.0-2.fc33
anaconda-33.25.4-1.fc33

I'm not seeing this with a 3x device btrfs volume in a data/metadata single profile configuration. So maybe it's fixed? Or maybe it's transient?

Comment 10 Chris Murphy 2021-02-14 07:22:50 UTC
Transient. I've done over two dozen installations of Rawhide over the past couple months and hit it today with Fedora-Workstation-Live-x86_64-34-20210213.n.0.iso

python3-blivet-3.3.2-2.fc34.noarch
anaconda-34.24.2-1.fc34.x86_64

Comment 11 Chris Murphy 2021-02-14 07:23:46 UTC
Created attachment 1756897 [details]
fstab - f34

Comment 12 Chris Murphy 2021-02-14 07:24:20 UTC
Created attachment 1756898 [details]
program.log - f34

Comment 13 Chris Murphy 2021-02-14 07:24:48 UTC
Created attachment 1756899 [details]
storage.log - f34

Comment 14 Chris Murphy 2021-02-14 07:25:07 UTC
Created attachment 1756900 [details]
anaconda.log - f34

Comment 15 Chris Murphy 2021-02-14 07:26:02 UTC
Created attachment 1756901 [details]
storage.state

Comment 16 Chris Murphy 2021-02-14 07:26:31 UTC
Created attachment 1756902 [details]
journalctl out

Comment 17 Chris Murphy 2021-02-14 08:18:38 UTC
Feb 14 02:04:18 localhost-live org.fedoraproject.Anaconda.Modules.Storage[2358]: INFO:program:Running [30] mkfs.btrfs --label fedorapool --data single /dev/vda2 ...
Feb 14 02:04:18 localhost-live kernel: BTRFS: device label fedorapool devid 1 transid 5 /dev/vda2 scanned by mkfs.btrfs (2538)

Looks like udev setup the symlinks soon after mkfs.

# stat /dev/disk/by-uuid/6c699fd6-a1c0-424f-8dd5-d19f9c6d5135 
  File: /dev/disk/by-uuid/6c699fd6-a1c0-424f-8dd5-d19f9c6d5135 -> ../../vda2
  Size: 10        	Blocks: 0          IO Block: 4096   symbolic link
Device: 5h/5d	Inode: 541         Links: 1
Access: (0777/lrwxrwxrwx)  Uid: (    0/    root)   Gid: (    0/    root)
Context: system_u:object_r:device_t:s0
Access: 2021-02-14 02:53:33.319220007 -0500
Modify: 2021-02-14 02:04:19.980063296 -0500
Change: 2021-02-14 02:04:19.980063296 -0500
 Birth: -


https://github.com/storaged-project/blivet/blob/3.4-devel/blivet/devices/btrfs.py#L77
https://github.com/storaged-project/blivet/blob/3.4-devel/blivet/devices/btrfs.py#L149

But I'm lost where it gets the UUID from; maybe something needs a debug line so we have a chance of catching the problem in action?

Comment 18 Chris Murphy 2021-02-23 17:47:32 UTC
Created attachment 1758893 [details]
another example

Another case, where / and /boot are on separate Btrfs file systems (testing anaconda PR 3196).

fstab:
UUID=29be48ab-7c7f-4ad2-9f25-cad65270b3f2 /                       btrfs   subvol=root,compress=zstd:1 0 0
/dev/vda3               /boot                   btrfs   subvol=boot,compress=zstd:1 0 0

mkfs times:
Feb 23 12:00:41 org.fedoraproject.Anaconda.Modules.Storage[2638]: INFO:program:Running [30] mkfs.btrfs --label fedorapool --data single /dev/vda2 ...
Feb 23 12:00:41 kernel: BTRFS: device label fedorapool devid 1 transid 5 /dev/vda2 scanned by mkfs.btrfs (2834)
Feb 23 12:00:43 org.fedoraproject.Anaconda.Modules.Storage[2638]: INFO:program:Running [33] mkfs.btrfs --label fedoraboot --data single /dev/vda3 ...
Feb 23 12:00:43 kernel: BTRFS: device label fedoraboot devid 1 transid 5 /dev/vda3 scanned by mkfs.btrfs (2900)

fstab created
-rw-rw-r--. 1 root root 720 Feb 23 12:04 /mnt/sysimage/etc/fstab

I captured udevadm info for vda2 and vda3 before the fstab was created, the only difference is the order of information but both reflect fs UUID. So do sysfs and blkid at this time.

Pretty weird. Is it a race?

tar contains:
journalctl log
/tmp/*log
/tmp/*state
fstab
ESP's grub.cfg
udevadm info

Comment 19 David Lehman 2021-02-23 18:12:09 UTC
Yeah, it's almost certainly a race. We could put the block from BTRFSVolumeDevice._post_create into a loop w/ sleep so it tries maybe five times w/ 0.5s sleep between. There's a similar one in ActionCreateFormat.execute that we'd probably want to give the same treatment. What do you think, Vojtech?

Comment 20 Chris Murphy 2021-02-23 21:28:28 UTC
Created attachment 1758949 [details]
journal.log with udev.log-priority=debug

OK yet another VM install :P Includes PR 3196, and udev.log-priority=debug

fstab:
UUID=190e67f6-a55c-42e7-9283-3fec868c0a40 /                       btrfs   subvol=root,compress=zstd:1 0 0
UUID=5b7cd5d1-6c6f-442d-b329-99e13630bd63 /boot                   btrfs   subvol=boot,compress=zstd:1 0 0

However...

# cat /mnt/sysimage/boot/efi/EFI/fedora/grub.cfg
search --no-floppy --fs-uuid --set=dev None
set prefix=($dev)/boot/grub2

export $prefix
configfile $prefix/grub.cfg
#

And yet the order:

# ls -l /mnt/sysimage/etc/fstab
-rw-rw-r--. 1 root root 738 Feb 23 15:36 /mnt/sysimage/etc/fstab

# ls -l /mnt/sysimage/boot/efi/EFI/fedora/grub.cfg
-rwx------. 1 root root 117 Feb 23 15:40 /mnt/sysimage/boot/efi/EFI/fedora/grub.cfg

I guess there must be more than one discovery method and variable for the boot fs uuid. The fstab case seems to be racy, whereas the grub.cfg is always None but only on Btrfs.

Attaching only 'journalctl -b -o short-monotonic --no-hostname'

Comment 21 David Lehman 2021-02-23 21:53:06 UTC
Chris, what does /boot/grub2/device.map look like?

Comment 22 David Lehman 2021-02-23 22:09:32 UTC
Nevermind about device.map. I think the problem is that EFIGRUB.write_config is using stage2_device.format.uuid. I think it should use stage2_device.format.vol_uuid instead. I don't remember the exact details of why, except that it has to do with BTRFS overloading the concept of FS UUID.

Comment 23 Vojtech Trefny 2021-03-01 12:44:55 UTC
I have a workaround for this, unfortunately I wasn't able to reproduce the issue so I can't tell if it really helps, but it should, because we are no longer depending on UDev database.

upstream PR: https://github.com/storaged-project/blivet/pull/936

updates image: https://vtrefny.fedorapeople.org/img/rhbz1860602.img


Note You need to log in before you can comment on or make changes to this bug.