Bug 1686464

Summary: Not able to create Fedora 30 image with local kick file
Product: [Fedora] Fedora Reporter: Matej Marušák <mmarusak>
Component: virt-managerAssignee: Cole Robinson <crobinso>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 30CC: anaconda-maint-list, berrange, crobinso, dracut-maint-list, jonathan, jszinger, kellin, vanmeeuwen+fedora, vponcova, wwoods, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: virt-manager-2.1.0-2.fc30 virt-manager-2.1.0-2.fc29 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-04-14 00:01:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Log when running F30 image build with kickstart file none

Description Matej Marušák 2019-03-07 14:00:27 UTC
Created attachment 1541846 [details]
Log when running F30 image build with kickstart file

Description of problem:
Not able to create Fedora 30 image with custom kick file, but able to create Fedora 29 image with exactly the same kickstart and commandline.

How reproducible:
This is for F29, which works:
$ qemu-img create -f qcow2 /var/tmp/f29.qcow2 12G

$ virt-install --connect=qemu:///session --initrd-inject=fedora.ks '--extra-args=ks=file:/fedora.ks console=ttyS0,115200' --name=f29.qcow2-builder --disk path=/var/tmp/f29.qcow2,format=qcow2 --ram 4096 --vcpus=1 --os-type linux --os-variant fedora29 --location=https://dl.fedoraproject.org/pub/fedora/linux/releases/29/Server/x86_64/os/ --nographics --noreboot

This is for Fedora 30 which does not work:
$ qemu-img create -f qcow2 /var/tmp/f30.qcow2 12G

$ virt-install --connect=qemu:///session --initrd-inject=fedora.ks '--extra-args=ks=file:/fedora.ks console=ttyS0,115200' --name=f30.qcow2-builder --disk path=/var/tmp/f30.qcow2,format=qcow2 --ram 4096 --vcpus=1 --os-type linux --os-variant fedora29 --location=https://dl.fedoraproject.org/pub/fedora/linux/development/30/Server/x86_64/os/ --nographics --noreboot


Actual results:
Building for F30 fails, see attached log file. When no kickstart file used, I can get to anaconda.

$ cat fedora.ks
text
shutdown
lang en_US.UTF-8
keyboard us
network --bootproto dhcp
rootpw foobar
firewall --enabled --ssh
selinux --enforcing
timezone --utc America/New_York
bootloader --location=mbr --append="console=ttyS0,115200 rd_NO_PLYMOUTH"
zerombr
clearpart --all --initlabel
autopart

%packages
@core
%end


Last few lines from the log file:

[  OK  ] Started Open-iSCSI.
[   10.783183] 8021q: adding VLAN 0 to HW filter on device enp1s0
[   10.900989] IPv6: ADDRCONF(NETDEV_CHANGE): enp1s0: link becomes ready
[   10.902899] pciehp 0000:00:01.6:pcie004: Timeout on hotplug command 0x06f1 (issued 2031 msec ago)
[   11.925063] pciehp 0000:00:01.6:pcie004: Timeout on hotplug command 0x07f1 (issued 1020 msec ago)
[   12.768120] dracut-initqueue[911]: RTNETLINK answers: File exists
[   12.948906] pciehp 0000:00:01.6:pcie004: Timeout on hotplug command 0x0771 (issued 1018 msec ago)
[   14.681717] dracut-initqueue[911]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
[   14.683286] dracut-initqueue[911]:                                  Dload  Upload   Total   Spent    Left  Speed
100  479M  100  479M    0     0  2994k      0  0:02:43  0:02:43 --:--:-- 5595k
[  180.966090] dracut-initqueue[911]: losetup: cannot find an unused loop device: No such device
[  180.967909] dracut-initqueue[911]: losetup: /tmp/curl_fetch_url1/install.img: failed to use device: No such device
[  180.970824] dracut-initqueue[911]: mount: /run/initramfs/squashfs: can't find in /etc/fstab.
[  181.079121] dracut: FATAL: Failed to find a root filesystem in /tmp/curl_fetch_url1/install.img.
[  181.080376] dracut: Refusing to continue
[  181.101605] printk: systemd-shutdow: 22 output lines suppressed due to ratelimiting
[  181.109733] systemd-shutdown[1]: Syncing filesystems and block devices.
[  181.111038] systemd-shutdown[1]: Sending SIGTERM to remaining processes...
[  181.117364] systemd-journald[307]: Received SIGTERM from PID 1 (systemd-shutdow).
[  181.126079] systemd-shutdown[1]: Sending SIGKILL to remaining processes...
[  181.128558] systemd-shutdown[1]: Unmounting file systems.
[  181.130270] [1322]: Remounting '/var/lib/nfs/rpc_pipefs' read-only in with options '(null)'.
[  181.132638] [1323]: Unmounting '/var/lib/nfs/rpc_pipefs'.
[  181.134328] [1324]: Remounting '/' read-only in with options 'size=1980512k,nr_inodes=495128'.
[  181.136341] systemd-shutdown[1]: All filesystems unmounted.
[  181.137133] systemd-shutdown[1]: Deactivating swaps.
[  181.137819] systemd-shutdown[1]: All swaps deactivated.
[  181.138563] systemd-shutdown[1]: Detaching loop devices.
[  181.139598] systemd-shutdown[1]: All loop devices detached.
[  181.140547] systemd-shutdown[1]: Detaching DM devices.
[  181.145967] pciehp 0000:00:01.6:pcie004: Timeout on hotplug command 0x0771 (issued 168195 msec ago)
[  181.151025] pciehp 0000:00:01.5:pcie004: Timeout on hotplug command 0x11f1 (issued 176630 msec ago)
[  181.155894] pciehp 0000:00:01.4:pcie004: Timeout on hotplug command 0x11f1 (issued 176643 msec ago)
[  181.159914] pciehp 0000:00:01.3:pcie004: Timeout on hotplug command 0x11f1 (issued 176653 msec ago)
[  181.164961] pciehp 0000:00:01.2:pcie004: Timeout on hotplug command 0x11f1 (issued 176664 msec ago)
[  181.169992] pciehp 0000:00:01.1:pcie004: Timeout on hotplug command 0x11f1 (issued 176676 msec ago)
[  181.173933] pciehp 0000:00:01.0:pcie004: Timeout on hotplug command 0x11f1 (issued 176685 msec ago)
[  181.177606] reboot: System halted


Expected results:
Fedora 30 image successfully builds as does Fedora 29

Comment 1 Vendula Poncova 2019-03-08 10:26:42 UTC
I don't know what is the problem, but Anaconda doesn't seem to be involved at this point. Reassigning to dracut.

Comment 2 Matej Marušák 2019-03-14 07:33:43 UTC
Is there any progress on this? This should be fairly simple to reproduce.

P.S. Wanted to add needinfo to dracut-maint-list but it says that account is disabled.

Comment 3 Matej Marušák 2019-03-20 09:15:12 UTC
It seems it is related to `--initrd-inject=fedora.ks`, because if I upload the kickstart file to web and pass it as url it works.

This works, even though the kickstart file is the same:
$ virt-install --connect=qemu:///session '--extra-args=ks=https://mmarusak.fedorapeople.org/fedora.ks console=ttyS0,115200' --name=f30.qcow2-builder --disk path=/var/tmp/f30.qcow2,format=qcow2 --ram 4096 --vcpus=1 --os-type linux --os-variant fedora29 --location=https://dl.fedoraproject.org/pub/fedora/linux/development/30/Server/x86_64/os/ --nographics --noreboot

Comment 4 Matej Marušák 2019-03-20 10:56:21 UTC
Switching to virt-install, as this seems like better place now.

Comment 5 James Szinger 2019-03-22 15:12:44 UTC
I believe the problem is that --inject-initrd changes the ownership of the initrd / directory and the F30 systemd newly enforces directory ownership for systemd-tmpfiles-setup-dev.service.

Running virt-install with '--initrd-inject f30-mate.ks --extra-args 'ks=file:/f30-mate.ks rd.shell console=ttyS0' I get

[   23.300517] dracut-initqueue[955]: losetup: cannot find an unused loop device: No such device
[   23.303889] dracut-initqueue[955]: losetup: /tmp/curl_fetch_url1/install.img: failed to use device: No such device
[   23.309889] dracut-initqueue[955]: mount: /run/initramfs/squashfs: can't find in /etc/fstab.
[   23.673934] dracut: FATAL: Failed to find a root filesystem in /tmp/curl_fetch_url1/install.img.
[   23.675619] dracut: Refusing to continue

dracut:/# ls -la /
total 20
drwxrwxr-x  12  701  500  440 Mar 22 14:56 .
drwxrwxr-x  12  701  500  440 Mar 22 14:56 ..
-rw-rw-r--   1 root root  168 Feb 14 20:03 .buildstamp
-rw-r--r--   1 root root    0 Mar 22 14:56 .console_lock
lrwxrwxrwx   1 root root    7 Feb 14 20:03 bin -> usr/bin
drwxr-xr-x  16 root root 3140 Mar 22 14:56 dev
-rw-r--r--   1 root root  652 Mar 22 14:56 dracut-state.sh
drwxr-xr-x  16 root root  760 Mar 22 14:56 etc
-rw-r--r--   1  701  500 4537 Mar 22 14:56 f30-mate.ks
lrwxrwxrwx   1 root root   23 Feb 14 20:03 init -> usr/lib/systemd/systemd
lrwxrwxrwx   1 root root    7 Feb 14 20:03 lib -> usr/lib
lrwxrwxrwx   1 root root    9 Feb 14 20:03 lib64 -> usr/lib64
dr-xr-xr-x 139 root root    0 Mar 22 14:56 proc
drwxr-xr-x   2 root root   40 Feb 14 20:03 root
drwxr-xr-x  15 root root  420 Mar 22 14:56 run
lrwxrwxrwx   1 root root    8 Feb 14 20:03 sbin -> usr/sbin
-rwxr-xr-x   1 root root 3121 Feb 14 20:03 shutdown
dr-xr-xr-x  13 root root    0 Mar 22 14:56 sys
drwxr-xr-x   2 root root   40 Feb 14 20:03 sysroot
drwxrwxr-x   6 root root  580 Mar 22 14:56 tmp
drwxrwxr-x   9 root root  180 Feb 14 20:03 usr
drwxr-xr-x   5 root root  160 Mar 22 14:56 var
dracut:/# 

Note that / and f30-mate.ks are owned by UID 701, which is the UID I ran virt-install with.

journalctl shows the following errors:
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev/net.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev/vfio.
Mar 22 14:56:12 localhost systemd-tmpfiles[329]: Detected unsafe path transition / → /dev during canonicalization of /dev.

As a result /dev/loop-control is not created, losetup fails, and the real root is not mounted.


Proposed fix: --initrd-inject should preserve the ownership of /

Comment 6 James Szinger 2019-03-22 15:23:04 UTC
I don't see anything is the systemd release notes about this change, but this bug report 
<https://github.com/systemd/systemd/issues/11282> confirms that it is the expected behavior.

Comment 7 Zbigniew Jędrzejewski-Szmek 2019-03-25 21:47:15 UTC
Yes, we made systemd-tmpfiles (and other programs in the systemd project) much more careful when resolving file system paths. The general problem is that if we go through a directory owned by non-root, the owner of that directory can try to trick systemd-tmpfiles by switching symlinks between the time of check and the time of use. A decision was made to also change the code to apply the same rules also for things that are not symlinks, for simplicity and consistency. See https://github.com/systemd/systemd/issues/7986.

From our side, the best solution would be to change --initrd-inject to not set modify the ownership of "/", since that's ugly and a bug on its own.

Comment 8 Cole Robinson 2019-04-02 18:58:06 UTC
This is roughly how initrdinject works:

mkdir $tmpdir
cp foo.ks $tmpdir
cd $tmpdir
find . -print0 | cpio --create --null --quiet --format=newc | gzip >> $initrd

Except that's all in python with subprocess calls. So essentially it's gzip appending a cpio archive to the initrd. The cpio archive is just:

  /foo.ks

And that seems enough to change the root dir permissions in the initrd. cpio has some options about changing/preserving owner/group but it seems related to only the extraction options, nothing about for building an archive.

I'm not super familiar with dracut/initrd magic so I'm not really sure where else to look. Any suggestions?

Comment 9 James Szinger 2019-04-03 14:56:38 UTC
My limited testing shows that 

cpio --create --null --quiet --format=newc --owner +0:+0

creates an archive with UID and GID set to root.

mkdir foo
cd foo
date > date

find .| cpio --quiet -H newc               -o > ../foo.cpio  # uses the user's UID and GID
find .| cpio --quiet -H newc --owner +0:+0 -o > ../foo0.cpio # uses root's UID and GID

cd ..
cpio -t -v -i <foo.cpio  # shows dir and file owned by user
cpio -t -v -i <foo0.cpio # shows dir and file owned by root

Hope this helps

Comment 10 Cole Robinson 2019-04-03 16:15:29 UTC
Thanks James, a quick test shows me it fixes --initrd-inject with f30 URLs. If more testing goes fine I'll do a build today or tomorrow

Comment 11 Fedora Update System 2019-04-04 00:43:46 UTC
virt-manager-2.1.0-2.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-165f2eb025

Comment 12 Fedora Update System 2019-04-04 18:06:56 UTC
virt-manager-2.1.0-2.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-165f2eb025

Comment 13 Fedora Update System 2019-04-14 00:01:38 UTC
virt-manager-2.1.0-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.

Comment 14 James Szinger 2019-04-16 14:24:47 UTC
Please backport to Fedora 28 and 29.

Comment 15 Fedora Update System 2019-04-17 00:24:55 UTC
virt-manager-2.1.0-2.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2019-c6a78dbb35

Comment 16 Cole Robinson 2019-04-17 00:27:29 UTC
(In reply to James Szinger from comment #14)
> Please backport to Fedora 28 and 29.

I pushed an update for f29.
f28 is EOL soon enough, I'd rather people just use virt-preview repo if they need this fix on f28

Comment 17 Fedora Update System 2019-04-18 22:13:05 UTC
virt-manager-2.1.0-2.fc29 has been pushed to the Fedora 29 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-c6a78dbb35

Comment 18 Fedora Update System 2019-04-26 22:29:06 UTC
virt-manager-2.1.0-2.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.