dib fails unmounting loopback file system

Bug #1782030 reported by Amrith Kumar on 2018-07-16
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
diskimage-builder
Undecided
Unassigned

Bug Description

In creating an image, I see a failure at the very end during the mkfs stage. Initially I thought this was just another case of 1698337. Looking a little further, and after testing again, here is the error I am seeing.

2018-07-16 20:32:53.496 | cp: cannot stat '/tmp/tmp.2Jmw2aGGJZ/boot/*': No such file or directory
2018-07-16 20:32:53.499 | + /usr/local/lib/python2.7/dist-packages/diskimage_builder/lib/common-functions:run_d:1 : trap_cleanup
2018-07-16 20:32:53.500 | + /usr/local/lib/python2.7/dist-packages/diskimage_builder/lib/img-functions:trap_cleanup:36 : exitval=1
2018-07-16 20:32:53.502 | + /usr/local/lib/python2.7/dist-packages/diskimage_builder/lib/img-functions:trap_cleanup:37 : cleanup
2018-07-16 20:32:53.503 | + /usr/local/lib/python2.7/dist-packages/diskimage_builder/lib/img-functions:cleanup:42 : dib-block-device umount
2018-07-16 20:32:53.639 | DEBUG diskimage_builder.block_device.blockdevice [-] Creating BlockDevice object __init__ /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/blockdevice.py:228
2018-07-16 20:32:53.639 | DEBUG diskimage_builder.block_device.blockdevice [-] Params [{'root-fs-type': 'ext4', 'root-fs-opts': '-i 4096 -J size=64 ', 'root-label': None, 'build-dir': '/tmp/dib_build.ZNPIRlW7', 'image-size': '1664256KiB', 'image-dir': '/tmp/dib_image.AhhjLsyD', 'config': '/tmp/dib_build.ZNPIRlW7/block-device/config.yaml', 'mount-base': '/tmp/dib_build.ZNPIRlW7/mnt'}] __init__ /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/blockdevice.py:231
2018-07-16 20:32:53.644 | INFO diskimage_builder.block_device.level3.mount [-] Called for [mount_mkfs_boot]
2018-07-16 20:32:53.645 | INFO diskimage_builder.block_device.utils [-] Calling [sudo sync]
2018-07-16 20:32:53.657 | INFO diskimage_builder.block_device.utils [-] Calling [sudo umount /tmp/dib_build.ZNPIRlW7/mnt/boot]
2018-07-16 20:32:53.689 | INFO diskimage_builder.block_device.level3.mount [-] Called for [mount_mkfs_root]
2018-07-16 20:32:53.689 | INFO diskimage_builder.block_device.utils [-] Calling [sudo sync]
2018-07-16 20:32:53.700 | INFO diskimage_builder.block_device.utils [-] Calling [sudo fstrim --verbose /tmp/dib_build.ZNPIRlW7/mnt/]
2018-07-16 20:32:53.709 | DEBUG diskimage_builder.block_device.utils [-] exec_sudo: /tmp/dib_build.ZNPIRlW7/mnt/: 924.7 MiB (969629696 bytes) trimmed exec_sudo /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py:120
2018-07-16 20:32:53.709 | INFO diskimage_builder.block_device.utils [-] Calling [sudo umount /tmp/dib_build.ZNPIRlW7/mnt/]
2018-07-16 20:32:53.713 | DEBUG diskimage_builder.block_device.utils [-] exec_sudo: umount: /tmp/dib_build.ZNPIRlW7/mnt/: target is busy exec_sudo /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py:120
2018-07-16 20:32:53.713 | DEBUG diskimage_builder.block_device.utils [-] exec_sudo: (In some cases useful info about processes that exec_sudo /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py:120
2018-07-16 20:32:53.713 | DEBUG diskimage_builder.block_device.utils [-] exec_sudo: use the device is found by lsof(8) or fuser(1).) exec_sudo /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py:120
2018-07-16 20:32:53.713 | Traceback (most recent call last):
2018-07-16 20:32:53.713 | File "/usr/local/bin/dib-block-device", line 10, in <module>
2018-07-16 20:32:53.713 | sys.exit(main())
2018-07-16 20:32:53.713 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/cmd.py", line 120, in main
2018-07-16 20:32:53.714 | return bdc.main()
2018-07-16 20:32:53.714 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/cmd.py", line 115, in main
2018-07-16 20:32:53.714 | self.args.func()
2018-07-16 20:32:53.714 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/cmd.py", line 39, in cmd_umount
2018-07-16 20:32:53.714 | self.bd.cmd_umount()
2018-07-16 20:32:53.714 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/blockdevice.py", line 441, in cmd_umount
2018-07-16 20:32:53.714 | node.umount()
2018-07-16 20:32:53.714 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/level3/mount.py", line 112, in umount
2018-07-16 20:32:53.714 | exec_sudo(["umount", self.state['mount'][self.mount_point]['path']])
2018-07-16 20:32:53.714 | File "/usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py", line 125, in exec_sudo
2018-07-16 20:32:53.714 | ' '.join(sudo_cmd))
2018-07-16 20:32:53.714 | subprocess.CalledProcessError: Command 'sudo umount /tmp/dib_build.ZNPIRlW7/mnt/' returned non-zero exit status 32

Observe that the order of things seems to be

2018-07-16 20:32:53.657 | INFO diskimage_builder.block_device.utils [-] Calling [sudo umount /tmp/dib_build.ZNPIRlW7/mnt/boot]
2018-07-16 20:32:53.689 | INFO diskimage_builder.block_device.level3.mount [-] Called for [mount_mkfs_root]
2018-07-16 20:32:53.689 | INFO diskimage_builder.block_device.utils [-] Calling [sudo sync]

2018-07-16 20:32:53.709 | DEBUG diskimage_builder.block_device.utils [-] exec_sudo: /tmp/dib_build.ZNPIRlW7/mnt/: 924.7 MiB (969629696 bytes) trimmed exec_sudo /usr/local/lib/python2.7/dist-packages/diskimage_builder/block_device/utils.py:120
2018-07-16 20:32:53.709 | INFO diskimage_builder.block_device.utils [-] Calling [sudo umount /tmp/dib_build.ZNPIRlW7/mnt/]

Looking at the mounts on my machine now, I see the following.

/dev/mapper/loop0p2 on /tmp/dib_build.ZNPIRlW7/mnt type ext4 (rw,relatime,data=ordered)
none on /tmp/dib_build.ZNPIRlW7/mnt/proc type proc (rw,relatime)
udev on /tmp/dib_build.ZNPIRlW7/mnt/dev type devtmpfs (rw,nosuid,relatime,size=16404408k,nr_inodes=4101102,mode=755)
devpts on /tmp/dib_build.ZNPIRlW7/mnt/dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
none on /tmp/dib_build.ZNPIRlW7/mnt/sys type sysfs (rw,relatime)
/dev/loop1 on /tmp/tmp.N3KMyREdeg type vfat (rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro)
/dev/loop2 on /tmp/tmp.2Jmw2aGGJZ type ext4 (rw,relatime,data=ordered)

--

You can't umount /tmp/dib_build.ZNPIRlW7/mnt/boot, it isn't something that we're currently mounting.

    amrith@amrith-m4800:~/source/diskimage-builder/diskimage_builder$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/boot
    umount: /tmp/dib_build.ZNPIRlW7/mnt/boot: not mounted
    amrith@amrith-m4800:~/source/diskimage-builder/diskimage_builder$ echo $?
    32

Now, since this fails, we seem to be attempting to umount /tmp/dib_build.ZNPIRlW7/mnt/

    Of course, you can't do that now ...

    amrith@amrith-m4800:~/source/diskimage-builder/diskimage_builder$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/
    umount: /tmp/dib_build.ZNPIRlW7/mnt/: target is busy
        (In some cases useful info about processes that
         use the device is found by lsof(8) or fuser(1).)

    Why?

        Because we've got a bunch of stuff mounted under /tmp/dib_build.ZNPIRlW7/mnt/

        amrith@amrith-m4800:~$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/proc
        amrith@amrith-m4800:~$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/dev/pts
        amrith@amrith-m4800:~$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/dev/
        amrith@amrith-m4800:~$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/sys
        amrith@amrith-m4800:~$ sudo umount /tmp/dib_build.ZNPIRlW7/mnt/
        amrith@amrith-m4800:~$

I'm not sure what caused those mounts to happen, but sure enough they did ...

Amrith Kumar (amrith) wrote :
Ian Wienand (iwienand) wrote :

Please always attach a full log if you can; the real error can be a long way before the resulting failure.

Also it matters what elements and distribution you're building.

The /dev, /sys etc mounts are expected as they are created inside the chroot. But, as noted, we may not clean them up quite correctly.

I'm not sure why you wouldn't have a "/boot" ... it's the type of thing that might have failed earlier in the build; and we have assumptions it is there that get invalidated. I can't really tell what lead up to this issue occuring

Changed in diskimage-builder:
status: New → Incomplete
Amrith Kumar (amrith) wrote :

I think this is user error.

Changed in diskimage-builder:
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Bug attachments