Rudd-O / zfs-fedora-installer

Fedora on ZFS root installer
35 stars 6 forks source link

Script fails with Device 'ide-hd' could not be initialized #7

Closed bra-fsn closed 8 years ago

bra-fsn commented 10 years ago

I run the script (up to date ATM) with: ./install-fedora-on-zfs --separate-boot boot.img --host-name finestra --luks-password PASS --releasever 20 volume.img and get this error in the end: DEBUG:root:Check calling 'losetup' '-d' '/dev/loop0' in cwd '/usr/src/zfs-fedora-installer' DEBUG:root:Check calling 'losetup' '-d' '/dev/loop1' in cwd '/usr/src/zfs-fedora-installer' DEBUG:root:Check calling 'qemu-kvm' '-nographic' '-serial' '/dev/stdout' '-name' 'finestra' '-M' 'pc-1.2' '-no-reboot' '-m' '1024' '-uuid' '27484500-7e79-11e3-839e-f0def1e14563' '-kernel' '/dev/shm/tmph91QfC/vmlinuz-3.12.7-300.fc20.x86_64' '-initrd' '/dev/shm/tmph91QfC/initramfs-3.12.7-300.fc20.x86_64.img' '-append' 'rd.luks.uuid=8e55840e-7d18-43f1-ae18-b6dd7317e7e3 rd.luks.key=/key console=ttyS0 root=ZFS=tank/ROOT/os ro init=/installbootloader' '-enable-kvm' '-drive' 'file=boot.img,if=none,id=drive-ide0-0-0,format=raw' '-device' 'ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1' '-drive' 'file=volume.img,if=none,id=drive-ide0-1-0,format=raw' '-device' 'ide-hd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=2' '-drive' 'file=/dev/shm/tmph91QfC/keydev.img,if=none,id=drive-ide1-0-0,format=raw' '-device' 'ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3' in cwd '/usr/src/zfs-fedora-installer' QEMU 1.6.1 monitor - type 'help' for more information (qemu) qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: IDE unit 0 is in use qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: Device initialization failed. qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: Device 'ide-hd' could not be initialized Traceback (most recent call last): File "./install-fedora-on-zfs", line 796, in sys.exit(main()) File "./install-fedora-on-zfs", line 788, in main args.luksoptions, File "./install-fedora-on-zfs", line 725, in install_fedora check_call(cmd) File "./install-fedora-on-zfs", line 82, in check_call return subprocess.check_call(args,*kwargs) File "/usr/lib64/python2.7/subprocess.py", line 542, in check_call raise CalledProcessError(retcode, cmd) subprocess.CalledProcessError: Command '['qemu-kvm', '-nographic', '-serial', '/dev/stdout', '-name', 'finestra', '-M', 'pc-1.2', '-no-reboot', '-m', '1024', '-uuid', '27484500-7e79-11e3-839e-f0def1e14563', '-kernel', '/dev/shm/tmph91QfC/vmlinuz-3.12.7-300.fc20.x86_64', '-initrd', '/dev/shm/tmph91QfC/initramfs-3.12.7-300.fc20.x86_64.img', '-append', 'rd.luks.uuid=8e55840e-7d18-43f1-ae18-b6dd7317e7e3 rd.luks.key=/key console=ttyS0 root=ZFS=tank/ROOT/os ro init=/installbootloader', '-enable-kvm', '-drive', 'file=boot.img,if=none,id=drive-ide0-0-0,format=raw', '-device', 'ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1', '-drive', 'file=volume.img,if=none,id=drive-ide0-1-0,format=raw', '-device', 'ide-hd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=2', '-drive', 'file=/dev/shm/tmph91QfC/keydev.img,if=none,id=drive-ide1-0-0,format=raw', '-device', 'ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3']' returned non-zero exit status 1

This is on a fedora 20 default install.

Rudd-O commented 10 years ago

It seems to be the case that when this takes place, the device file keydev.img in /dev/shm/..../ is somehow not closed prior to the execution of qemu. I cannot repro this locally, but I would love to help you repro this remotely.

Can you add a subprocess.call(["bash"]) right before the qemu command invocation, and then check out what is holding keydev.img open, perhaps with lsof -n or mount?

Can you also figure out if you can reproduce this reliably?

According to line https://github.com/Rudd-O/zfs-fedora-installer/blob/master/install-fedora-on-zfs#L679 the keydev.img file ought to be unmounted (and therefore should not be in use) by the time qemu is being prepared to be executed.

Thanks in advance.

On 01/15/2014 10:52 PM, bra-fsn wrote:

I run the script (up to date ATM) with: ./install-fedora-on-zfs --separate-boot boot.img --host-name finestra --luks-password PASS --releasever 20 volume.img and get this error in the end: DEBUG:root:Check calling 'losetup' '-d' '/dev/loop0' in cwd '/usr/src/zfs-fedora-installer' DEBUG:root:Check calling 'losetup' '-d' '/dev/loop1' in cwd '/usr/src/zfs-fedora-installer' DEBUG:root:Check calling 'qemu-kvm' '-nographic' '-serial' '/dev/stdout' '-name' 'finestra' '-M' 'pc-1.2' '-no-reboot' '-m' '1024' '-uuid' '27484500-7e79-11e3-839e-f0def1e14563' '-kernel' '/dev/shm/tmph91QfC/vmlinuz-3.12.7-300.fc20.x86_64' '-initrd' '/dev/shm/tmph91QfC/initramfs-3.12.7-300.fc20.x86_64.img' '-append' 'rd.luks.uuid=8e55840e-7d18-43f1-ae18-b6dd7317e7e3 rd.luks.key=/key console=ttyS0 root=ZFS=tank/ROOT/os ro init=/installbootloader' '-enable-kvm' '-drive' 'file=boot.img,if=none,id=drive-ide0-0-0,format=raw' '-device' 'ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1' '-drive' 'file=volume.img,if=none,id=drive-ide0-1-0,format=raw' '-device' 'ide-hd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=2' '-drive' 'file=/dev/shm/tmph91QfC/keydev.img,if=none,id=drive-ide1-0-0,format=raw' '-device' 'ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3' in cwd '/usr/src/zfs-fedora-installer' QEMU 1.6.1 monitor - type 'help' for more information (qemu) qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: IDE unit 0 is in use qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: Device initialization failed. qemu-system-x86_64: -device ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3: Device 'ide-hd' could not be initialized Traceback (most recent call last): File "./install-fedora-on-zfs", line 796, in sys.exit(main()) File "./install-fedora-on-zfs", line 788, in main args.luksoptions, File "./install-fedora-on-zfs", line 725, in install_fedora check_call(cmd) File "./install-fedora-on-zfs", line 82, in check_call return subprocess.check_call(/args,/*kwargs) File "/usr/lib64/python2.7/subprocess.py", line 542, in check_call raise CalledProcessError(retcode, cmd) subprocess.CalledProcessError: Command '['qemu-kvm', '-nographic', '-serial', '/dev/stdout', '-name', 'finestra', '-M', 'pc-1.2', '-no-reboot', '-m', '1024', '-uuid', '27484500-7e79-11e3-839e-f0def1e14563', '-kernel', '/dev/shm/tmph91QfC/vmlinuz-3.12.7-300.fc20.x86_64', '-initrd', '/dev/shm/tmph91QfC/initramfs-3.12.7-300.fc20.x86_64.img', '-append', 'rd.luks.uuid=8e55840e-7d18-43f1-ae18-b6dd7317e7e3 rd.luks.key=/key console=ttyS0 root=ZFS=tank/ROOT/os ro init=/installbootloader', '-enable-kvm', '-drive', 'file=boot.img,if=none,id=drive-ide0-0-0,format=raw', '-device', 'ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1', '-drive', 'file=volume.img,if=none,id=drive-ide0-1-0,format=raw', '-device', 'ide-hd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=2', '-drive', 'file=/dev/shm/tmph91QfC/keydev.img,if=none,id=drive-ide1-0-0,format=raw', '-device', 'ide-hd,bus=ide.1,unit=0,drive=drive-ide1-0-0,id=ide1-0-0,bootindex=3']' returned non-zero exit status 1

This is on a fedora 20 default install.

— Reply to this email directly or view it on GitHub https://github.com/Rudd-O/zfs-fedora-installer/issues/7.

bra-fsn commented 10 years ago

Sorry for the delay, ext4 sometimes fail on this machine, so I had to put the whole stuff to an external drive.. The last lines before the line (724) I put the bash into are: DEBUG:root:Check calling 'mkfs.ext4' '-F' '/dev/shm/tmpHLpyxU/keydev.img' in cwd '/ssd/zfs-fedora-installer' mke2fs 1.42.8 (20-Jun-2013)

Filesystem too small for a journal Discarding device blocks: done
Filesystem label= OS type: Linux Block size=1024 (log=0) Fragment size=1024 (log=0) Stride=0 blocks, Stripe width=0 blocks 16 inodes, 100 blocks 5 blocks (5.00%) reserved for the super user First data block=1 1 block group 8192 blocks per group, 8192 fragments per group 16 inodes per group

Allocating group tables: done
Writing inode tables: done
Writing superblocks and filesystem accounting information: done

DEBUG:root:Check calling 'mount' '/dev/shm/tmpHLpyxU/keydev.img' '/dev/shm/tmpHLpyxU/keydev' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'sync' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'umount' '/mnt/tank/boot' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'umount' '/mnt/tank/sys' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'umount' '/mnt/tank/proc' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'umount' '/dev/shm/tmpxPmlyj/keydev' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'zpool' 'export' 'tank' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'cryptsetup' 'luksClose' 'luks-793df62a-e4b2-4efc-b09d-a8af18225389' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'losetup' '-d' '/dev/loop0' in cwd '/ssd/zfs-fedora-installer' DEBUG:root:Check calling 'losetup' '-d' '/dev/loop1' in cwd '/ssd/zfs-fedora-installer'

mount says:

mount

proc on /proc type proc (rw,nosuid,nodev,noexec,relatime) sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime) devtmpfs on /dev type devtmpfs (rw,nosuid,size=1956420k,nr_inodes=489105,mode=755) securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev) devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) tmpfs on /sys/fs/cgroup type tmpfs (rw,nosuid,nodev,noexec,mode=755) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/usr/lib/systemd/systemd-cgroups-agent,name=systemd) pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime) cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset) cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpuacct,cpu) cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event) cgroup on /sys/fs/cgroup/hugetlb type cgroup (rw,nosuid,nodev,noexec,relatime,hugetlb) /dev/mapper/fedora-root on / type ext4 (rw,relatime,data=ordered) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=34,pgrp=1,timeout=300,minproto=5,maxproto=5,direct) tmpfs on /tmp type tmpfs (rw) mqueue on /dev/mqueue type mqueue (rw,relatime) debugfs on /sys/kernel/debug type debugfs (rw,relatime) hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) /dev/sda2 on /boot type ext4 (rw,relatime,data=ordered) /dev/mapper/fedora-home on /home type ext4 (rw,relatime,data=ordered) fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime) gvfsd-fuse on /run/user/1000/gvfs type fuse.gvfsd-fuse (rw,nosuid,nodev,relatime,user_id=1000,group_id=1000) /dev/sdb on /ssd type ext3 (rw,relatime,data=ordered)

I see nothing with keydev.

umount /dev/shm/tmpHLpyxU/keydev.img

umount: /dev/shm/tmpHLpyxU/keydev.img: not mounted

ls -l /dev/shm/tmpHLpyxU/keydev.img

-rw-r--r-- 1 root root 102400 Jan 22 07:15 /dev/shm/tmpHLpyxU/keydev.img

The file itself is readable:

md5sum /dev/shm/tmpHLpyxU/keydev.img

8b6245ea279484ed01eae6a72b6dcc47 /dev/shm/tmpHLpyxU/keydev.img

losetup -l shows nothing.

Rudd-O commented 10 years ago

This is very very baffling.

I see nothing that could keep that image file "open" from the standpoint of QEMU attempting to access it and failing.

It does happen to me sometimes that losetup'd files remain in a "open" state even though they don't show on the list of files losetup -l, and in those cases I have to reboot in order to get it to work. But I've never experienced this.

Rudd-O commented 8 years ago

Please message me again if you can still repro the issue. It's been two years and I cannot reproduce it.