'losetup' crashes when attempted to create a Fedora disk image

[Kashyap Chamarthy]

To reproduce, invoke disk-image-create with complete trace enabled, and attempt to create a Fedora image:

  $ git clone https://github.com/stackforge/diskimage-builder.git
  $ cd disk-image-builder
  $ export PATH=$PATH:/home/kashyap/src/diskimage-builder/bin
  $ disk-image-create -o fedora-test fedora -a i386 -x

+ true
+ case "$1" in
+ shift
+ break
+ '[' '' = 1 -a /root '!=' '' ']'
+ source /home/kashyap/src/diskimage-builder/bin/../lib/img-defaults
++ source /home/kashyap/src/diskimage-builder/bin/../lib/common-defaults
+++ '[' -f /etc/debian_version ']'
++++ uname -m
+++ _ARCH=x86_64
+++ case $_ARCH in
+++ _ARCH=amd64
+++ ARCH=i386
+++ export ARCH
+++ export DIB_NO_TMPFS=0
+++ DIB_NO_TMPFS=0
++++ dirname /home/kashyap/src/diskimage-builder/bin/disk-image-create
+++ _BASE_ELEMENT_DIR=/home/kashyap/src/diskimage-builder/bin/../elements
+++ ELEMENTS_PATH=
+++ export ELEMENTS_PATH=/home/kashyap/src/diskimage-builder/bin/../elements
+++ ELEMENTS_PATH=/home/kashyap/src/diskimage-builder/bin/../elements
++ FS_TYPE=ext4
++ IMAGE_TYPE=qcow2
++ IMAGE_NAME=fedora-test
+ source /home/kashyap/src/diskimage-builder/bin/../lib/common-functions
+ source /home/kashyap/src/diskimage-builder/bin/../lib/img-functions
+ arg_to_elements fedora
+ for arg in '"$@"'
+ IMAGE_ELEMENT=' fedora'
+ '[' '' '!=' 1 ']'
+ IMAGE_ELEMENT='base fedora'
+ echo 'Building elements: base fedora'
Building elements: base fedora
+ echo 'If prompted for sudo, install sudoers.d/img-build-sudoers into /etc/sudoers.d and restart the build.'
If prompted for sudo, install sudoers.d/img-build-sudoers into /etc/sudoers.d and restart the build.
++ /home/kashyap/src/diskimage-builder/bin/element-info --expand-dependencies base fedora
+ IMAGE_ELEMENT='dib-run-parts dracut-network base fedora cache-url'
+ echo 'Expanded element dependencies to: dib-run-parts dracut-network base fedora cache-url'
Expanded element dependencies to: dib-run-parts dracut-network base fedora cache-url
+ IMAGE_NAME=fedora-test
+ mk_build_dir
++ mktemp -t -d --tmpdir=/tmp image.XXXXXXXX
+ export TMP_BUILD_DIR=/tmp/image.XWWZNOAm
+ TMP_BUILD_DIR=/tmp/image.XWWZNOAm
+ '[' 0 -eq 0 ']'
+ tmpfs_check
+ '[' 0 == 0 ']'
+ '[' -r /proc/meminfo ']'
++ awk '/^MemTotal/ { print $2 }' /proc/meminfo
+ total_kB=23649504
+ '[' 23649504 -lt 4194304 ']'
+ return 0
+ sudo mount -t tmpfs tmpfs /tmp/image.XWWZNOAm
++ id -u
++ id -g
+ sudo chown 0:0 /tmp/image.XWWZNOAm
+ trap cleanup EXIT
+ echo Building in /tmp/image.XWWZNOAm
Building in /tmp/image.XWWZNOAm
+ export TMP_IMAGE_PATH=/tmp/image.XWWZNOAm/image.raw
+ TMP_IMAGE_PATH=/tmp/image.XWWZNOAm/image.raw
+ export TMP_HOOKS_PATH=/tmp/image.XWWZNOAm/hooks
+ TMP_HOOKS_PATH=/tmp/image.XWWZNOAm/hooks
+ create_base
+ mkdir /tmp/image.XWWZNOAm/mnt
+ export TMP_MOUNT_PATH=/tmp/image.XWWZNOAm/mnt
+ TMP_MOUNT_PATH=/tmp/image.XWWZNOAm/mnt
+ TARGET_ROOT=/tmp/image.XWWZNOAm/mnt
+ run_d root
+ check_element
+ '[' -d /tmp/image.XWWZNOAm/hooks ']'
+ generate_hooks
+ mkdir -p /tmp/image.XWWZNOAm/hooks
+ for _ELEMENT in '$IMAGE_ELEMENT'
++ echo /home/kashyap/src/diskimage-builder/bin/../elements
++ tr : ' '
+ for dir in '$(echo $ELEMENTS_PATH | tr ":" " ")'
+ '[' -d /home/kashyap/src/diskimage-builder/bin/../elements/dib-run-parts ']'
+ cp -t /tmp/image.XWWZNOAm/hooks -a /home/kashyap/src/diskimage-builder/bin/../elements/dib-run-parts/root.d
+ break
+ for _ELEMENT in '$IMAGE_ELEMENT'
++ echo /home/kashyap/src/diskimage-builder/bin/../elements
++ tr : ' '
+ for dir in '$(echo $ELEMENTS_PATH | tr ":" " ")'
+ '[' -d /home/kashyap/src/diskimage-builder/bin/../elements/dracut-network ']'
+ cp -t /tmp/image.XWWZNOAm/hooks -a /home/kashyap/src/diskimage-builder/bin/../elements/dracut-network/README.md /home/kashyap/src/diskimage-builder/bin/../elements/dracut-network/dracut-write-ifcfg.patch /home
/kashyap/src/diskimage-builder/bin/../elements/dracut-network/finalise.d /home/kashyap/src/diskimage-builder/bin/../elements/dracut-network/install.d
+ break
+ for _ELEMENT in '$IMAGE_ELEMENT'
++ echo /home/kashyap/src/diskimage-builder/bin/../elements
++ tr : ' '
+ for dir in '$(echo $ELEMENTS_PATH | tr ":" " ")'
+ '[' -d /home/kashyap/src/diskimage-builder/bin/../elements/base ']'
+ cp -t /tmp/image.XWWZNOAm/hooks -a /home/kashyap/src/diskimage-builder/bin/../elements/base/README.md /home/kashyap/src/diskimage-builder/bin/../elements/base/dib-first-boot /home/kashyap/src/diskimage-builder
/bin/../elements/base/extra-data.d /home/kashyap/src/diskimage-builder/bin/../elements/base/finalise.d /home/kashyap/src/diskimage-builder/bin/../elements/base/install.d /home/kashyap/src/diskimage-builder/bin/.
./elements/base/post-install.d /home/kashyap/src/diskimage-builder/bin/../elements/base/pre-install.d
+ break
+ for _ELEMENT in '$IMAGE_ELEMENT'
++ echo /home/kashyap/src/diskimage-builder/bin/../elements
++ tr : ' '
+ for dir in '$(echo $ELEMENTS_PATH | tr ":" " ")'
+ '[' -d /home/kashyap/src/diskimage-builder/bin/../elements/fedora ']'
+ cp -t /tmp/image.XWWZNOAm/hooks -a /home/kashyap/src/diskimage-builder/bin/../elements/fedora/README.md /home/kashyap/src/diskimage-builder/bin/../elements/fedora/bin /home/kashyap/src/diskimage-builder/bin/..
/elements/fedora/element-deps /home/kashyap/src/diskimage-builder/bin/../elements/fedora/finalise.d /home/kashyap/src/diskimage-builder/bin/../elements/fedora/install.d /home/kashyap/src/diskimage-builder/bin/..
/elements/fedora/post-install.d /home/kashyap/src/diskimage-builder/bin/../elements/fedora/pre-install.d /home/kashyap/src/diskimage-builder/bin/../elements/fedora/root.d
+ break
+ for _ELEMENT in '$IMAGE_ELEMENT'
++ echo /home/kashyap/src/diskimage-builder/bin/../elements
++ tr : ' '
+ for dir in '$(echo $ELEMENTS_PATH | tr ":" " ")'
+ '[' -d /home/kashyap/src/diskimage-builder/bin/../elements/cache-url ']'
+ cp -t /tmp/image.XWWZNOAm/hooks -a /home/kashyap/src/diskimage-builder/bin/../elements/cache-url/README.md /home/kashyap/src/diskimage-builder/bin/../elements/cache-url/bin
+ break
+ check_break before-root bash
+ echo ''
+ egrep -e '(,|^)before-root(,|$)' -q
+ '[' -d /tmp/image.XWWZNOAm/hooks/root.d ']'
+ run-parts /tmp/image.XWWZNOAm/hooks/root.d
/tmp/image.XWWZNOAm/hooks/root.d/10-fedora-cloud-image:

Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 216M 100 216M 0 0 212k 0 0:17:21 0:17:21 --:--:-- 132k
Downloaded and cached http://mattdm.fedorapeople.org/cloud-images//Fedora18-Cloud-i386-latest.qcow2 for the first time
Repacking base image as tarball.
Working in /tmp/tmp.5ypJ7B4vjn
mount: could not find any device /dev/loop#Bad address
can't set up loop
mount: /dev/mapper is not a block device
+ check_break after-root bash
+ echo ''
+ egrep -e '(,|^)after-root(,|$)' -q
++ ls /tmp/image.XWWZNOAm/mnt
++ grep -v lost+found
+ '[' -z usr ']'
+ '[' -L /tmp/image.XWWZNOAm/mnt/etc/resolv.conf ']'
+ '[' -f /tmp/image.XWWZNOAm/mnt/etc/resolv.conf ']'
+ sudo touch /tmp/image.XWWZNOAm/mnt/etc/resolv.conf
touch: cannot touch '/tmp/image.XWWZNOAm/mnt/etc/resolv.conf': No such file or directory
+ cleanup
+ unmount_image
+ sudo umount -f /tmp/image.XWWZNOAm/mnt/sys
umount: /tmp/image.XWWZNOAm/mnt/sys: not found
+ true
+ sudo umount -f /tmp/image.XWWZNOAm/mnt/proc
umount: /tmp/image.XWWZNOAm/mnt/proc: not found
+ true
+ sudo umount -f /tmp/image.XWWZNOAm/mnt/dev
umount: /tmp/image.XWWZNOAm/mnt/dev: not found
+ true
+ sudo umount -f /tmp/image.XWWZNOAm/mnt/tmp/in_target.d
umount: /tmp/image.XWWZNOAm/mnt/tmp/in_target.d: not found
+ true
+ sleep 5
+ sudo umount -f /tmp/image.XWWZNOAm/mnt
umount: /tmp/image.XWWZNOAm/mnt: not mounted
+ true
+ sync
+ '[' -n '' ']'
+ cleanup_dirs
+ sudo rm -rf /tmp/image.XWWZNOAm/built
+ sudo rm -rf /tmp/image.XWWZNOAm/mnt
+ sudo umount -f /tmp/image.XWWZNOAm
+ rm -rf /tmp/image.XWWZNOAm

[Kashyap Chamarthy (kashyapc)]

Re-invoking it again fails to set up loop device:

   $ disk-image-create -o fedora-test fedora -a i386 -x

.
.
.
+ echo ''
+ egrep -e '(,|^)before-root(,|$)' -q
+ '[' -d /tmp/image.tsgcLWGl/hooks/root.d ']'
+ run-parts /tmp/image.tsgcLWGl/hooks/root.d
/tmp/image.tsgcLWGl/hooks/root.d/10-fedora-cloud-image:

Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0
Server copy has not changed. Using locally cached http://mattdm.fedorapeople.org/cloud-images//Fedora18-Cloud-i386-latest.qcow2
Repacking base image as tarball.
Working in /tmp/tmp.sDrZzw96Zx
mount: could not find any free loop deviceBad address
can't set up loop
mount: /dev/mapper is not a block device
+ check_break after-root bash
+ echo ''
+ egrep -e '(,|^)after-root(,|$)' -q
++ ls /tmp/image.tsgcLWGl/mnt
++ grep -v lost+found
+ '[' -z usr ']'
+ '[' -L /tmp/image.tsgcLWGl/mnt/etc/resolv.conf ']'
+ '[' -f /tmp/image.tsgcLWGl/mnt/etc/resolv.conf ']'
+ sudo touch /tmp/image.tsgcLWGl/mnt/etc/resolv.conf
touch: cannot touch '/tmp/image.tsgcLWGl/mnt/etc/resolv.conf': No such file or directory
+ cleanup
+ unmount_image
+ sudo umount -f /tmp/image.tsgcLWGl/mnt/sys
umount: /tmp/image.tsgcLWGl/mnt/sys: not found
+ true
+ sudo umount -f /tmp/image.tsgcLWGl/mnt/proc
umount: /tmp/image.tsgcLWGl/mnt/proc: not found
+ true
+ sudo umount -f /tmp/image.tsgcLWGl/mnt/dev
umount: /tmp/image.tsgcLWGl/mnt/dev: not found
+ true
+ sudo umount -f /tmp/image.tsgcLWGl/mnt/tmp/in_target.d
umount: /tmp/image.tsgcLWGl/mnt/tmp/in_target.d: not found
+ true
+ sleep 5
+ sudo umount -f /tmp/image.tsgcLWGl/mnt
umount: /tmp/image.tsgcLWGl/mnt: not mounted
+ true
+ sync
+ '[' -n '' ']'
+ cleanup_dirs
+ sudo rm -rf /tmp/image.tsgcLWGl/built
+ sudo rm -rf /tmp/image.tsgcLWGl/mnt
+ sudo umount -f /tmp/image.tsgcLWGl
+ rm -rf /tmp/image.tsgcLWGl

[Robert Collins (lifeless)]

This is almost certainly a Fedora issue - unless you can reproduce it I think this should be filed upstream - does Fedora capture stackdumps automatically for problem analysis?

[Kashyap Chamarthy (kashyapc)]

Couple of notes:

 - What stackdump. are you requesting? (NOTE: Fedora uses 'abrt', I tried to see if anything was captured in
/var/spool/abrt-upload/ -- which is where it dumps any crash data, I couldn't find any).

 - Lucas Alvaro Gomes on IRC (#tripleo) mentioned he got it working with some dependencies resolved on Fedora-19 VM, pointing to a dependencies script

    https://raw.github.com/tripleo/incubator/master/scripts/install-dependencies

So, it's not entirely an 'upstream' bug or a Fedora issue.

I have all the deps mentioned in the above file for noted under "$os" = "redhat"
-----
  $ rpm -q python-lxml libvirt-python libvirt qemu-img qemu-kvm git python-pip openssl-devel python-devel gcc audit python-virtualenv openvswitch
python-lxml-3.2.1-1.fc19.x86_64
libvirt-python-1.0.6-3.fc19.x86_64
libvirt-1.0.6-3.fc19.x86_64
qemu-img-1.5.0-9.fc19.x86_64
qemu-kvm-1.5.0-9.fc19.x86_64
git-1.8.3.1-1.fc19.x86_64
python-pip-1.3.1-1.fc19.noarch
openssl-devel-1.0.1e-4.fc19.x86_64
python-devel-2.7.5-1.fc19.x86_64
gcc-4.8.1-1.fc19.x86_64
audit-2.3.1-2.fc19.x86_64
python-virtualenv-1.9.1-1.fc19.noarch
openvswitch-1.10.0-1.fc19.x86_64
-----

Perhaps README has to be updated clearly with further details on what are the per-requisites?

Please correct me if I'm still doing something utterly wrong here.

[Robert Collins (lifeless)]

There's no indication that it's a dependency issue. AFAICT Lucas was just reporting that it works for him.

[Robert Collins (lifeless)]

So, what we need is to capture what is printing bad address out. Can you run it with strace -ff and see if you can find the source of the 'Bad Address' output?

[Robert Collins (lifeless)]

19:25 < kashyap> It tried to 'stat' all 255 loop devices..
19:25 < kashyap> [pid 24018] stat("/dev/loop/253", 0x7fff07e70ba0) = -1 ENOENT (No such file or directory)
19:25 < kashyap> [pid 24018] stat("/dev/loop/254", 0x7fff07e70ba0) = -1 ENOENT (No such file or directory)
19:25 < kashyap> [pid 24018] stat("/dev/loop/255", 0x7fff07e70ba0) = -1 ENOENT (No such file or directory)
19:25 < kashyap> mount: could not find any free loop deviceBad address
19:25 < kashyap> can't set up loop

[Robert Collins (lifeless)]

http://osdir.com/ml/debian.devel.live/2008-08/msg00024.html
http://lkml.indiana.edu/hypermail/linux/kernel/0509.1/0468.html

[Kashyap Chamarthy (kashyapc)]

"AFAICT Lucas was just reporting that it works for him." -- Not sure what additional deps he had.

Meanwhile, just tried with 'strace'

I tried a:

 $ modprobe loop; echo $?
 0

And, then:

 $ strace -ff disk-image-create -o fedora-test2 fedora \
    -a i386 -x 2>&1 | tee /var/tmp/dib-log3.txt

It tries to stat all loop devices (255 times), and finally fails:
==========
[pid 24279] stat("/dev/loop2", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
[pid 24279] stat("/dev/loop3", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
[pid 24279] stat("/dev/loop4", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
[pid 24279] stat("/dev/loop5", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
.
.
.
[pid 24279] stat("/dev/loop/254", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
[pid 24279] stat("/dev/loop/255", 0x7fffb27b1120) = -1 ENOENT (No such file or directory)
.
.
.
mount: could not find any free loop deviceBad address
can't set up loop
mount: /dev/mapper is not a block device
) = 779
[pid 24254] exit_group(0) = ?
[pid 24254] +++ exited with 0 +++
.
.
==========

[Kashyap Chamarthy (kashyapc)]

Complete stack trace here (10MB file)

  http://kashyapc.fedorapeople.org/virt/openstack/dib-log.txt

[Lucas Alvares Gomes (lucasagomes)]

I just gave dib a spin on the new FC19 (freshly installed on a VM) and I was able to generate the image, but I also hit a different problem than the one you've reported.

So the steps I did (after installing the OS on the vm) was:

1- yum install git
2- clone the incubator and diskimage-builder repo
3- generated one rsa key for my user (ssh-keygen -t rsa)
4- ran the incubator/scripts/install-dependencies script
5***- ran ./bin/disk-image-create -o fedora-test fedora -a i386 -x

The first time I ran the diskimage-create script I got the following error (complete log: http://paste.fedoraproject.org/22675/):
mount: special device /dev/mapper/loop0p2 does not exist

So there's a bug on the script that doesn't check if the device is ready before trying to mount it, I opened a ticket for it: https://bugs.launchpad.net/diskimage-builder/+bug/1197340.
And then, I gave it a second try and ran it again, this time I got the image generated successfully (complete log: http://paste.fedoraproject.org/22676/)

So, I'm not being able to reproduce what you've reported but if there's any output/logs you need from my VM lemme know. For now I'm attaching the output of the "rpm -qa" command in case you think it's a dependency issue (http://paste.fedoraproject.org/22677/).

[Richard Su (rwsu)]

I wasn't able to reproduce the error Kashyap saw.

I am seeing the same error Lucas reported in http://paste.fedoraproject.org/22675/.

The workaround I have found is to add a 2 second sleep after this line in 10-fedora-cloud-image

    LOOPDEV=$(sudo kpartx -avr $WORKING/$RAW_FILE | awk "/loop[0-9]+$MAGIC_BIT/ {print \$3}")

I'll submit a more robust patch once I am back from the July 4th break.

[Kashyap Chamarthy (kashyapc)]

Ok, I'm able to reproduce what Lucas sees. I Just spun up a fresh Fedora-19, installed qemu-img, kapartx. and re-tried:

It throws a:

 " mount: special device /dev/mapper/loop0p2 does not exist"

  $ git log | head -1
  commit ad0fe876df8c7a8d45712163f143e48516b077b3

  $ free -m
             total used free shared buffers cached
Mem: 4727 208 4518 0 7 60
-/+ buffers/cache: 140 4586
Swap: 1535 0 1535

  $ disk-image-create -o fedora-test fedora -a i386 2>&1 | tee /var/tmp/dib-log-n1.txt
Building elements: base fedora
If prompted for sudo, install sudoers.d/img-build-sudoers into /etc/sudoers.d and restart the build.
Expanded element dependencies to: dib-run-parts dracut-network base fedora cache-url
Building in /tmp/image.8tHb6B77
/tmp/image.8tHb6B77/hooks/root.d/10-fedora-cloud-image:

Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0
Server copy has not changed. Using locally cached http://mattdm.fedorapeople.org/cloud-images//Fedora18-Cloud-i386-latest.qcow2
Repacking base image as tarball.
Working in /tmp/tmp.QG4QqAMuuJ
mount: special device /dev/mapper/loop0p2 does not exist
loop deleted : /dev/loop0
touch: cannot touch '/tmp/image.8tHb6B77/mnt/etc/resolv.conf': No such file or directory
umount: /tmp/image.8tHb6B77/mnt/sys: not found
umount: /tmp/image.8tHb6B77/mnt/proc: not found
umount: /tmp/image.8tHb6B77/mnt/dev: not found
umount: /tmp/image.8tHb6B77/mnt/tmp/in_target.d: not found
umount: /tmp/image.8tHb6B77/mnt: not mounted

[Richard Su (rwsu)]

Lucas submitted a bug for the /dev/mapper/loop0p2 does not exist issue in https://bugs.launchpad.net/diskimage-builder/+bug/1197340.

And I just submitted a patch for it in https://review.openstack.org/35871.

Are you able to reproduce the original error? If not, then perhaps we can close this bug.

[Kashyap Chamarthy (kashyapc)]

Ok. with this git commit, I got the qcow2 image created just fine.

  $ git log | head -1
  commit 9a81644d6518098a6f33286aecbe5adbe59744c6

  $ disk-image-create -o fedora-test fedora -a i386 \
      2>&1 | tee /var/tmp/dib-log.txt
.
.
.
+ cat /tmp/tmp.4s5Un4BhtE
Warning: Skipping the following R/O filesystems:
/tmp/in_target.d
+ rm /tmp/tmp.4s5Un4BhtE
dib-run-parts Tue Jul 9 02:38:00 EDT 2013 11-selinux-fixfiles-restore completed
dib-run-parts Tue Jul 9 02:38:00 EDT 2013 Running /tmp/in_target.d/finalise.d/98-regenerate-initramfs
dib-run-parts Tue Jul 9 02:38:31 EDT 2013 98-regenerate-initramfs completed
dib-run-parts Tue Jul 9 02:38:31 EDT 2013 Running /tmp/in_target.d/finalise.d/99-setup-first-boot
dib-run-parts Tue Jul 9 02:38:31 EDT 2013 99-setup-first-boot completed
----------------------- PROFILING -----------------------

Target: finalise.d

Script Seconds
--------------------------------------- ----------

01-install-dib-first-boot 0.006
11-selinux-fixfiles-restore 64.305
99-setup-first-boot 0.007
98-regenerate-initramfs 30.849

--------------------- END PROFILING ---------------------
umount: /tmp/image.I6Ybmrrb/mnt/tmp/in_target.d: not found
Image file fedora-test.qcow2 created...

[Kashyap Chamarthy (kashyapc)]

Richard, please feel free to close this bug.

[Kashyap Chamarthy (kashyapc)]

Ok, I can consistently reproduce this now, with F19 images:

git commit:
-------------

  $ git log | head -1
  commit 9f93451710a5da370b10d7f657910c2f332723e3

Invocation:
------------

  $ disk-image-create -o fedora19.qcow2 fedora -a amd64 2>&1 | tee /var/tmp/dib-log-f19-take3.txt
Building elements: base fedora
If prompted for sudo, install sudoers.d/img-build-sudoers into /etc/sudoers.d and restart the build.
Expanded element dependencies to: dib-run-parts dracut-network base fedora cache-url
Building in /tmp/image.Qx74swlM
/tmp/image.Qx74swlM/hooks/root.d/10-fedora-cloud-image:

Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- 0:00:05 --:--:-- 0
100 226M 100 226M 0 0 8576k 0 0:00:27 0:00:27 --:--:-- 10.1M
Downloaded and cached http://download.fedoraproject.org/pub/fedora/linux/releases/19/Images/x86_64/Fedora-x86_64-19-20130627-sda.qcow2 for the first time
Repacking base image as tarball.
Working in /tmp/tmp.Fv6pmSw2dP
mount: /dev/mapper is not a block device
loop deleted : /dev/loop0
/tmp/image.Qx74swlM/hooks/root.d/10-fedora-cloud-image.k:

Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
100 269 100 269 0 0 379 0 --:--:-- --:--:-- --:--:-- 379
Server returned an unexpected response code. [404]
touch: cannot touch '/tmp/image.Qx74swlM/mnt/etc/resolv.conf': No such file or directory
umount: /tmp/image.Qx74swlM/mnt/sys: not found
umount: /tmp/image.Qx74swlM/mnt/proc: not found
umount: /tmp/image.Qx74swlM/mnt/dev: not found
umount: /tmp/image.Qx74swlM/mnt/tmp/in_target.d: not found
umount: /tmp/image.Qx74swlM/mnt: not mounted
[root@f19x86_64e root.d]#

[Richard Su (rwsu)]

I don't think folks have been able reproduce this bug. A few other Red Hatters have been able to build f19 images. So I'm setting the status to incomplete for now.

[Robert Collins (lifeless)]

Closing invalid - two months with no reproduction instructions.

[Kashyap Chamarthy (kashyapc)]

Robert, sorry, I haven't had a chance to try this in a couple of months, been buried in other work.

So, from your previous comment, it must be have been 'fixed' with latest git.

[Kashyap Chamarthy (kashyapc)]

I'm able to reproduce this on Fedora 20 with current head:

    $ cat /etc/fedora-release
    Fedora release 20 (Heisenbug)
    $ git clone https://github.com/openstack/diskimage-builder.git
    $ git log | head -1
    commit 09a8fca8d0d461c76a41d0332f44af4c9d94f0b1
    $ cd diskimage-builder
    $ export PATH=$PATH:/home/kashyap/src/diskimage-builder/bin
    $ disk-image-create -o fedora-test fedora -a i386 -x
.
.
.
dib-run-parts Mon Jan 6 13:06:24 IST 2014 Running /tmp/image.6qlcG6Wg/hooks/root.d/10-fedora-cloud-image
Fetching Base Image
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 406 100 406 0 0 471 0 --:--:-- --:--:-- --:--:-- 471
  0 0 0 0 0 0 0 0 --:--:-- 0:00:03 --:--:-- 0
100 224M 100 224M 0 0 9719k 0 0:00:23 0:00:23 --:--:-- 11.0M
Downloaded and cached http://cloud.fedoraproject.org/fedora-19.i386.qcow2 for the first time
Repacking base image as tarball.
Working in /tmp/tmp.Ph4kjDBOcA
mount: could not find any device /dev/loop#Bad address
can't set up loop
mount: /dev/mapper is not a block device
+ cleanup
+ unmount_image
+ sync
+ unmount_dir /tmp/image.6qlcG6Wg/mnt
+ local pattern=/tmp/image.6qlcG6Wg/mnt mnts=
+ '[' -n /tmp/image.6qlcG6Wg/mnt ']'
++ awk '{print $2}'
++ grep '^/tmp/image.6qlcG6Wg/mnt'
++ sort -r
+ mnts=/tmp/image.6qlcG6Wg/mnt/tmp/ccache
+ '[' -n /tmp/image.6qlcG6Wg/mnt/tmp/ccache ']'
+ sudo umount -fl /tmp/image.6qlcG6Wg/mnt/tmp/ccache
+ '[' -n '' ']'
+ cleanup_dirs
+ sudo rm -rf /tmp/image.6qlcG6Wg/built
+ sudo rm -rf /tmp/image.6qlcG6Wg/mnt
+ sudo umount -f /tmp/image.6qlcG6Wg
+ rm -rf /tmp/image.6qlcG6Wg

[Ronelle Landy (rlandy)]

I can reproduce this error running the last of the devtest.html setup steps on Fedora 19:

>> $TRIPLEO_ROOT/diskimage-builder/bin/ramdisk-image-create -a $NODE_ARCH $NODE_DIST $DEPLOY_IMAGE_ELEMENT -o $TRIPLEO_ROOT/deploy-ramdisk 2>&1 | tee $TRIPLEO_ROOT/dib-deploy.log

<truncated output>
+ RV=0
+ set -e
+ '[' 0 == 44 ']'
+ '[' 0 '!=' 0 ']'
+ '[' '!' -f /root/.cache/image-create/19-Cloud-i386-19.tgz -o /root/.cache/image-create/fedora-19.i386.qcow2 -nt /root/.cache/image-create/19-Cloud-i386-19.tgz ']'
+ echo 'Repacking base image as tarball.'
Repacking base image as tarball.
++ mktemp -d
+ WORKING=/tmp/tmp.d2o611xBFT
+ EACTION='rm -r /tmp/tmp.d2o611xBFT'
+ trap 'rm -r /tmp/tmp.d2o611xBFT' EXIT
+ echo 'Working in /tmp/tmp.d2o611xBFT'
Working in /tmp/tmp.d2o611xBFT
++ basename fedora-19.i386.qcow2
+ RAW_FILE=fedora-19.i386.qcow2
+ RAW_FILE=fedora-19.i386.qcow2.raw
+ qemu-img convert -f qcow2 -O raw /root/.cache/image-create/fedora-19.i386.qcow2 /tmp/tmp.d2o611xBFT/fedora-19.i386.qcow2.raw
+ MAGIC_BIT=p1
++ sudo kpartx -av /tmp/tmp.d2o611xBFT/fedora-19.i386.qcow2.raw
++ awk '/loop[0-9]+p1/ {print $3}'
mount: could not find any device /dev/loop#Bad address
can't set up loop
+ LOOPDEV=
+ timeout 5 sh -c 'while ! [ -e /dev/mapper/ ]; do sleep 1; done'
+ EACTION='sudo kpartx -d /tmp/tmp.d2o611xBFT/fedora-19.i386.qcow2.raw;rm -r /tmp/tmp.d2o611xBFT'
+ trap 'sudo kpartx -d /tmp/tmp.d2o611xBFT/fedora-19.i386.qcow2.raw;rm -r /tmp/tmp.d2o611xBFT' EXIT
+ mkdir /tmp/tmp.d2o611xBFT/mnt
+ sudo mount /dev/mapper/ /tmp/tmp.d2o611xBFT/mnt
mount: /dev/mapper is not a block device
+ sudo kpartx -d /tmp/tmp.d2o611xBFT/fedora-19.i386.qcow2.raw
+ rm -r /tmp/tmp.d2o611xBFT
[root@cloud-qe-1-vm-2 tripleo]#

[Jan Provaznik (jan-provaznik)]

Ronelle Landy was able to reproduce on F19 now, the issue is that when loop module is loaded, no /dev/loop* device is created. Command "kpartx -av..." which is called in elements/fedora/root.d/10-fedora-cloud-image expects that there is a free loop device and fails if no free loop device is found. Calling "losetup -f" command which returns next free loop device and creates it solves the issue:

[root@cloud-qe-1-vm-2 tripleo]# ls -l /dev/loop*
crw-------. 1 root root 10, 237 Jan 6 04:17 /dev/loop-control
[root@cloud-qe-1-vm-2 tripleo]# kpartx -av /tmp/test.qcow2.raw
mount: could not find any device /dev/loop#Bad address
can't set up loop
[root@cloud-qe-1-vm-2 tripleo]# losetup
[root@cloud-qe-1-vm-2 tripleo]# losetup -f
/dev/loop0
[root@cloud-qe-1-vm-2 tripleo]# ls -l /dev/loop*
brw-rw----. 1 root disk 7, 0 Jan 6 04:23 /dev/loop0
crw-------. 1 root root 10, 237 Jan 6 04:17 /dev/loop-control
[root@cloud-qe-1-vm-2 tripleo]# kpartx -av /tmp/test.qcow2.raw
add map loop0p1 (253:2): 0 4000001 linear /dev/loop0 1953
[root@cloud-qe-1-vm-2 tripleo]#

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/65056

[Kashyap Chamarthy (kashyapc)]

Just tested locally, with the latest fix, works for me:

    $ git pull https://review.openstack.org/openstack/diskimage-builder refs/changes/56/65056/3
    $ git log | head -1
    commit 018dfb53d9ea2c6bdba46307ecb10b71aa0899c9
    $ disk-image-create -o fedora-test1 fedora -a x86_64
    $ echo $?
    0

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/65056
Committed: https://git.openstack.org/cgit/openstack/diskimage-builder/commit/?id=c9cceeeb4071f22633402b232e26c58d7e516514
Submitter: Jenkins
Branch: master

commit c9cceeeb4071f22633402b232e26c58d7e516514
Author: Jan Provaznik <email address hidden>
Date: Mon Jan 6 10:55:06 2014 +0100

    Make sure a loop device exists before kpartx is called

    If "kpartx -av" is called and there is no unused /dev/loop* device,
    then kpartx fails. Calling "losetup -f" finds first unused device
    and creates it if it doesn't exist.

    Fixes bug #1195264

    Change-Id: I5d59b519fd8e2a7380b71a788f9d3f2331b6567f