Description of problem: I was running a basic test (https://fedoraproject.org/wiki/QA:Testcase_Boot_default_install) with the rawhide workstation live boot ISO `Fedora-Workstation-Live-x86_64-Rawhide-20210721.n.0.iso` Booting is failing. Version-Release number of selected component (if applicable): 20210721 How reproducible: 100% - this has failed with UEFI in each build I have tried. I do not know when the problem was introduced - 20210713 is the first one I have used. Steps to Reproduce: 1. Create a Hyper-V Generation 2 VM on Windows 10 2. Disable secure boot 3. Attach `Fedora-Workstation-Live-x86_64-Rawhide-20210721.n.0.iso` 4. Start the VM Actual results: As the live image boots, it errors out with this message and does not proceed. ``` [ 2.802595] dracut-initqueue[724]: mount: rum/initramf s/live: special device /dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0 does not exist. [ 2.804403) dracut: FATAL: Failed to mount block device of live image [ 2.804420) dracut: Refusing to continue 2.849443] reboot: System halted ``` Expected results: No errors Additional info: Running on Windows 10 build 19042.1110 BIOS boots fine from the ISOs I have tried.
Created attachment 1804270 [details] rdsosreport Adding rdsosreport - this shows the media being remounted at a different point, which triggers a SCSI eject event.
The same media boots correctly with the VM set to BIOS mode
I just double checked the Fedora 34 Workstation Live ISO - it works fine with the same configuration. Some change in rawhide has broken this.
There seem to be two relevant sections that lead to ejecting the media. It seems that one rule is correctly preserving the symlinks to /dev/sr0: [ 3.099758] fedora systemd-udevd[575]: sr0: /etc/udev/rules.d/99-live-squash.rules:2 RUN '/sbin/initqueue --settled --onetime --unique /sbin/dmsquash-live-root /dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0' [ 3.099771] fedora systemd-udevd[575]: sr0: Handling device node '/dev/sr0', devnum=b11:0 [ 3.099793] fedora systemd-udevd[575]: sr0: Setting permissions /dev/sr0, uid=0, gid=11, mode=0660 [ 3.099808] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/cdrom' [ 3.099832] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/cdrom' to 'sr0' [ 3.099844] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-label\x2fFedora-WS-Live-rawh-20210721-n-0' [ 3.099855] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0' to '../../sr0' [ 3.100406] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-path\x2facpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' [ 3.100437] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/disk/by-path/acpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' to '../../sr0' [ 3.100452] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-id\x2fscsi-14d534654202020207305e3437703544694957d7ced624a7d' [ 3.100467] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/disk/by-id/scsi-14d534654202020207305e3437703544694957d7ced624a7d' to '../../sr0' [ 3.100480] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-uuid\x2f2021-07-21-08-21-35-00' [ 3.100493] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/disk/by-uuid/2021-07-21-08-21-35-00' to '../../sr0' [ 3.100505] fedora systemd-udevd[575]: sr0: Creating symlink '/dev/block/11:0' to '../sr0' [ 3.100518] fedora systemd-udevd[575]: sr0: sd-device: Created db file '/run/udev/data/b11:0' for '/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/0b66321f-d456-4963-8b1a-cc35020a7c00/host0/target0:0:0/0:0:0:0/block/sr0' [ 3.100531] fedora systemd-udevd[575]: sr0: Handling device node '/dev/sr0', devnum=b11:0 [ 3.100544] fedora systemd-udevd[575]: sr0: Preserve permissions of /dev/sr0, uid=0, gid=11, mode=0660 [ 3.100557] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/cdrom' [ 3.100569] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/cdrom' to 'sr0' [ 3.100581] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-label\x2fFedora-WS-Live-rawh-20210721-n-0' [ 3.100593] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0' to '../../sr0' [ 3.100606] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-path\x2facpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' [ 3.100618] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/disk/by-path/acpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' to '../../sr0' [ 3.100630] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-id\x2fscsi-14d534654202020207305e3437703544694957d7ced624a7d' [ 3.100642] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/disk/by-id/scsi-14d534654202020207305e3437703544694957d7ced624a7d' to '../../sr0' [ 3.100655] fedora systemd-udevd[575]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-uuid\x2f2021-07-21-08-21-35-00' [ 3.100667] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/disk/by-uuid/2021-07-21-08-21-35-00' to '../../sr0' [ 3.100679] fedora systemd-udevd[575]: sr0: Preserve already existing symlink '/dev/block/11:0' to '../sr0' Then a later one is choosing to eject sr0: [ 3.114641] fedora systemd-udevd[585]: sr0: Failed to get watch handle, ignoring: No such file or directory [ 3.114671] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/60-cdrom_id.rules:16 RUN 'cdrom_id --eject-media $devnode' [ 3.114199] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#124 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.115063] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/60-persistent-storage.rules:66 Importing properties from results of 'scsi_id --export --whitelisted -d /dev/sr0' [ 3.115108] fedora systemd-udevd[585]: sr0: Starting 'scsi_id --export --whitelisted -d /dev/sr0' [ 3.115143] fedora systemd-udevd[585]: Successfully forked off '(spawn)' as PID 643. [ 3.117993] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#126 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.118634] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#65 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.119075] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#67 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.119735] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#72 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.119875] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_SCSI=1' [ 3.119948] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_VENDOR=Msft' [ 3.119975] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_VENDOR_ENC=Msft\x20\x20\x20\x20' [ 3.119987] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_MODEL=Virtual_DVD-ROM' [ 3.119997] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_MODEL_ENC=Virtual\x20DVD-ROM\x20' [ 3.120007] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_REVISION=1.0' [ 3.120017] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_TYPE=cd' [ 3.120027] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_SERIAL=14d534654202020207305e3437703544694957d7ced624a7d' [ 3.120037] fedora systemd-udevd[585]: sr0: 'scsi_id --export --whitelisted -d /dev/sr0'(out) 'ID_SERIAL_SHORT=4d534654202020207305e3437703544694957d7ced624a7d' [ 3.120047] fedora systemd-udevd[585]: sr0: Process 'scsi_id --export --whitelisted -d /dev/sr0' succeeded. [ 3.120057] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/60-persistent-storage.rules:68 LINK 'disk/by-id/scsi-14d534654202020207305e3437703544694957d7ced624a7d' [ 3.120117] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/60-persistent-storage.rules:90 Importing properties from results of builtin command 'path_id' [ 3.120208] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/60-persistent-storage.rules:92 LINK 'disk/by-path/acpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' [ 3.120297] fedora systemd-udevd[585]: sr0: /usr/lib/udev/rules.d/73-seat-late.rules:16 RUN 'uaccess' [ 3.120315] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/cdrom', which is no longer belonging to this device. [ 3.120330] fedora systemd-udevd[585]: sr0: No reference left for '/dev/cdrom', removing [ 3.120342] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0', which is no longer belonging to this device. [ 3.120354] fedora systemd-udevd[585]: sr0: No reference left for '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0', removing [ 3.120368] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/disk/by-uuid/2021-07-21-08-21-35-00', which is no longer belonging to this device. [ 3.120381] fedora systemd-udevd[585]: sr0: No reference left for '/dev/disk/by-uuid/2021-07-21-08-21-35-00', removing [ 3.120391] fedora systemd-udevd[585]: sr0: Handling device node '/dev/sr0', devnum=b11:0 [ 3.120403] fedora systemd-udevd[585]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-id\x2fscsi-14d534654202020207305e3437703544694957d7ced624a7d' [ 3.120414] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/disk/by-id/scsi-14d534654202020207305e3437703544694957d7ced624a7d' to '../../sr0' [ 3.120426] fedora systemd-udevd[585]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-path\x2facpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' [ 3.120437] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/disk/by-path/acpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' to '../../sr0' [ 3.120448] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/block/11:0' to '../sr0' [ 3.120459] fedora systemd-udevd[585]: sr0: sd-device: Created db file '/run/udev/data/b11:0' for '/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/0b66321f-d456-4963-8b1a-cc35020a7c00/host0/target0:0:0/0:0:0:0/block/sr0' [ 3.120470] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/cdrom', which is no longer belonging to this device. [ 3.120481] fedora systemd-udevd[585]: sr0: No reference left for '/dev/cdrom', removing [ 3.120491] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0', which is no longer belonging to this device. [ 3.120503] fedora systemd-udevd[585]: sr0: No reference left for '/dev/disk/by-label/Fedora-WS-Live-rawh-20210721-n-0', removing [ 3.120513] fedora systemd-udevd[585]: sr0: Updating old device symlink '/dev/disk/by-uuid/2021-07-21-08-21-35-00', which is no longer belonging to this device. [ 3.120524] fedora systemd-udevd[585]: sr0: No reference left for '/dev/disk/by-uuid/2021-07-21-08-21-35-00', removing [ 3.120534] fedora systemd-udevd[585]: sr0: Handling device node '/dev/sr0', devnum=b11:0 [ 3.120544] fedora systemd-udevd[585]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-id\x2fscsi-14d534654202020207305e3437703544694957d7ced624a7d' [ 3.120555] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/disk/by-id/scsi-14d534654202020207305e3437703544694957d7ced624a7d' to '../../sr0' [ 3.120568] fedora systemd-udevd[585]: sr0: Found 'b11:0' claiming '/run/udev/links/disk\x2fby-path\x2facpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' [ 3.120578] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/disk/by-path/acpi-VMBUS:00-vmbus-0b66321fd45649638b1acc35020a7c00-lun-0' to '../../sr0' [ 3.120588] fedora systemd-udevd[585]: sr0: Preserve already existing symlink '/dev/block/11:0' to '../sr0' [ 3.120598] fedora systemd-udevd[585]: sr0: Running command "cdrom_id --eject-media /dev/sr0" [ 3.120611] fedora systemd-udevd[585]: sr0: Starting 'cdrom_id --eject-media /dev/sr0' (this is in the full rdsosreport attached)
The oldest rawhide nightly I could find was Fedora-Workstation-Live-x86_64-Rawhide-20210709.n.0.iso. It still reproduces there.
Looking again, I think that maybe this is the first failure (SEQNUM=1512), which upon failure maybe triggers the eject in SEQNUM=1520? I'm just guessing here [ 3.110910] fedora systemd-udevd[487]: sr0: SEQNUM=1520 blocked by SEQNUM=1512 [ 3.110956] fedora kernel: hv_storvsc 0b66321f-d456-4963-8b1a-cc35020a7c00: tag#17 cmd 0x0 status: scsi 0x0 srb 0x81 hv 0x0 [ 3.113031] fedora systemd[1]: dev-cdrom.device: Changed dead -> plugged [ 3.113063] fedora systemd[1]: dev-disk-by\x2did-scsi\x2d14d534654202020207305e3437703544694957d7ced624a7d.device: Changed dead -> plugged [ 3.113081] fedora systemd[1]: dev-disk-by\x2dlabel-Fedora\x2dWS\x2dLive\x2drawh\x2d20210721\x2dn\x2d0.device: Changed dead -> plugged [ 3.113093] fedora systemd[1]: dev-disk-by\x2dpath-acpi\x2dVMBUS:00\x2dvmbus\x2d0b66321fd45649638b1acc35020a7c00\x2dlun\x2d0.device: Changed dead -> plugged [ 3.113106] fedora systemd[1]: dev-disk-by\x2duuid-2021\x2d07\x2d21\x2d08\x2d21\x2d35\x2d00.device: Changed dead -> plugged [ 3.113118] fedora systemd[1]: dev-sr0.device: Changed dead -> plugged [ 3.113134] fedora systemd[1]: sys-devices-LNXSYSTM:00-LNXSYBUS:00-ACPI0004:00-VMBUS:00-0b66321f\x2dd456\x2d4963\x2d8b1a\x2dcc35020a7c00-host0-target0:0:0-0:0:0:0-block-sr0.device: Changed dead -> plugged [ 3.113146] fedora systemd-udevd[573]: 0:0:0:0: Processing device (SEQNUM=1512, ACTION=bind) [ 3.113160] fedora systemd-udevd[573]: 0:0:0:0: /usr/lib/udev/rules.d/50-udev-default.rules:14 Importing properties from results of builtin command 'hwdb --subsystem=scsi' [ 3.113173] fedora systemd-udevd[573]: 0:0:0:0: /usr/lib/udev/rules.d/50-udev-default.rules:14 Failed to run builtin 'hwdb --subsystem=scsi': Invalid argument [ 3.113184] fedora systemd-udevd[573]: 0:0:0:0: Device processed (SEQNUM=1512, ACTION=bind) [ 3.113195] fedora systemd-udevd[573]: 0:0:0:0: sd-device-monitor: Passed 280 byte to netlink monitor [ 3.113249] fedora systemd-udevd[487]: 0:0:0:0: Device ready for processing (SEQNUM=1513, ACTION=add) [ 3.113272] fedora systemd-udevd[487]: 0:0:0:0: sd-device-monitor: Passed 255 byte to netlink monitor [ 3.113284] fedora systemd-udevd[487]: sg0: Device ready for processing (SEQNUM=1514, ACTION=add) [ 3.113296] fedora systemd-udevd[487]: sg0: sd-device-monitor: Passed 287 byte to netlink monitor [ 3.113306] fedora systemd-udevd[487]: 0:0:0:0: Device ready for processing (SEQNUM=1515, ACTION=add) [ 3.113319] fedora systemd-udevd[487]: 0:0:0:0: sd-device-monitor: Passed 282 byte to netlink monitor [ 3.113329] fedora systemd-udevd[487]: sr0: Device ready for processing (SEQNUM=1520, ACTION=change) [ 3.113340] fedora systemd-udevd[487]: sr0: sd-device-monitor: Passed 330 byte to netlink monitor [ 3.113351] fedora systemd-udevd[585]: sr0: Processing device (SEQNUM=1520, ACTION=change)
See https://bugzilla.kernel.org/show_bug.cgi?id=213759, and this fix: https://lore.kernel.org/lkml/20210726114227.3661-1-limanyi@uniontech.com/.
Thanks for the pointer! It looks like that fix should be in 5.14-rc3, so I will recheck on a spin based on that kernel.
This is still happening in the latest rawhide workstation live ISO with kernel 5.14.0-0.rc3.20210728git4010a528219e.32.fc35.x86_64 Attached new logs, but the pattern is the same.
Created attachment 1809833 [details] Results from 20210731 live image
Oh, I think I misunderstood. The proposed fix in https://bugzilla.kernel.org/show_bug.cgi?id=213759#c7 is still not merged. I checked the sources this kernel was built from: https://gitlab.com/cki-project/kernel-ark/-/blob/kernel-5.14.0-0.rc3.20210728git4010a528219e.32/drivers/scsi/sr.c#L224
Thanks for the lead on this Michael! This change recently made it into rawhide just before it was branched. This is fixed, verified in https://kojipkgs.fedoraproject.org/compose/branched/Fedora-35-20210811.n.0/compose/Workstation/x86_64/iso/ I can boot up in UEFI mode, and have the expected enlightened drivers (hv_storvsc, ... and the new hyperv_drm). Resolution changing works too with the updated hyperv_drm driver!