vmbuilder fails using tmpfs due to upstart restarting cron in the tmpfs

Bug #1008225 reported by Tokuko
16
This bug affects 2 people
Affects Status Importance Assigned to Milestone
vm-builder (Ubuntu)
Fix Released
High
Unassigned
Precise
Fix Released
High
Unassigned

Bug Description

===============================
SRU Justification:
1. Impact: simple vm creations fail
2. Development fix: use dpkg-divert to replace initctl with our stub, so that when usptart is installed it does not replace it with the real one
3. Stable fix: same as development fix
4. Test case:
 sudo vmbuilder kvm ubuntu -o -v --tmpfs 1536 --rootsize=4096M --swapsize=512M -d vm1
5. Regression potential: The behavior is changed for all target releases, so a regression is not impossible. However I don't see anything which looks gragile, and without this fix it is definitely broken.

===============================
root@tina ~ # vmbuilder kvm ubuntu -d /srv/kvm/b --tmpfs - -m 4096 --ip 192.168.0.18 --hostname b --user tokudan --pass abc123 --addpkg openssh-server --addpkg unattended-upgrades --addpkg acpid
2012-06-03 22:37:12,118 INFO : Mounting tmpfs under /tmp/tmptcTxLBtmpfs
2012-06-03 22:37:12,446 INFO : Calling hook: preflight_check
2012-06-03 22:37:12,449 INFO : Calling hook: set_defaults
2012-06-03 22:37:12,449 INFO : Calling hook: bootstrap
2012-06-03 22:38:13,765 INFO : Calling hook: configure_os
2012-06-03 22:38:18,088 INFO : update-alternatives: error: no alternatives for rsh.
2012-06-03 22:38:18,127 INFO : update-alternatives: error: no alternatives for rlogin.
2012-06-03 22:38:18,166 INFO : update-alternatives: error: no alternatives for rcp.
2012-06-03 22:38:18,420 INFO : Creating SSH2 RSA key; this may take some time ...
2012-06-03 22:38:18,474 INFO : Creating SSH2 DSA key; this may take some time ...
2012-06-03 22:38:18,517 INFO :
2012-06-03 22:38:18,517 INFO : Warning: Fake initctl called, doing nothing
2012-06-03 22:38:18,517 INFO :
2012-06-03 22:38:18,517 INFO : Warning: Fake initctl called, doing nothing
2012-06-03 22:38:18,624 INFO : update-rc.d: warning: unattended-upgrades start runlevel arguments (none) do not match LSB Default-Start values (0 6)
2012-06-03 22:38:18,624 INFO : update-rc.d: warning: unattended-upgrades stop runlevel arguments (0 6) do not match LSB Default-Stop values (none)
2012-06-03 22:38:19,287 INFO :
2012-06-03 22:38:19,287 INFO : Current default time zone: 'Etc/UTC'
2012-06-03 22:38:19,290 INFO : Local time is now: Sun Jun 3 20:38:19 UTC 2012.
2012-06-03 22:38:19,290 INFO : Universal Time is now: Sun Jun 3 20:38:19 UTC 2012.
2012-06-03 22:38:19,290 INFO :
Extracting templates from packages: 100%
2012-06-03 22:38:24,563 INFO :
2012-06-03 22:38:24,563 INFO : Current default time zone: 'Etc/UTC'
2012-06-03 22:38:24,565 INFO : Local time is now: Sun Jun 3 20:38:24 UTC 2012.
2012-06-03 22:38:24,565 INFO : Universal Time is now: Sun Jun 3 20:38:24 UTC 2012.
2012-06-03 22:38:24,565 INFO : Run 'dpkg-reconfigure tzdata' if you wish to change it.
2012-06-03 22:38:24,565 INFO :
2012-06-03 22:38:26,026 INFO : stop: Unknown instance:
2012-06-03 22:38:27,353 INFO : Updating certificates in /etc/ssl/certs... WARNING: Skipping duplicate certificate brasil.gov.br.pem
2012-06-03 22:38:27,353 INFO : 0 added, 1 removed; done.
2012-06-03 22:38:27,354 INFO : Running hooks in /etc/ca-certificates/update.d....done.
2012-06-03 22:38:27,768 INFO : restart: Unknown instance:
2012-06-03 22:38:27,861 INFO : start: Unknown parameter: JOB
2012-06-03 22:38:28,082 INFO : umount: /tmp/tmptcTxLBtmpfs/dev: device is busy.
2012-06-03 22:38:28,082 INFO : (In some cases useful info about processes that use
2012-06-03 22:38:28,083 INFO : the device is found by lsof(8) or fuser(1))
2012-06-03 22:38:28,083 INFO : Cleaning up
2012-06-03 22:38:28,083 ERROR : Process (['umount', '/tmp/tmptcTxLBtmpfs/dev']) returned 1. stdout: , stderr: umount: /tmp/tmptcTxLBtmpfs/dev: device is busy.
        (In some cases useful info about processes that use
         the device is found by lsof(8) or fuser(1))

2012-06-03 22:38:28,083 INFO : Unmounting tmpfs from /tmp/tmptcTxLBtmpfs
2012-06-03 22:38:28,086 INFO : umount: /tmp/tmptcTxLBtmpfs: device is busy.
2012-06-03 22:38:28,087 INFO : (In some cases useful info about processes that use
2012-06-03 22:38:28,087 INFO : the device is found by lsof(8) or fuser(1))
Traceback (most recent call last):
  File "/usr/bin/vmbuilder", line 24, in <module>
    cli.main()
  File "/usr/lib/python2.7/dist-packages/VMBuilder/contrib/cli.py", line 239, in main
    util.clean_up_tmpfs(tmpfs_mount_point)
  File "/usr/lib/python2.7/dist-packages/VMBuilder/util.py", line 199, in clean_up_tmpfs
    run_cmd(*umount_cmd)
  File "/usr/lib/python2.7/dist-packages/VMBuilder/util.py", line 120, in run_cmd
    raise VMBuilderException, "Process (%s) returned %d. stdout: %s, stderr: %s" % (args.__repr__(), status, mystdout.buf, mystderr.buf)
VMBuilder.exception.VMBuilderException: Process (['umount', '-t', 'tmpfs', '/tmp/tmptcTxLBtmpfs']) returned 1. stdout: , stderr: umount: /tmp/tmptcTxLBtmpfs: device is busy.
        (In some cases useful info about processes that use
         the device is found by lsof(8) or fuser(1))

root@tina ~ # lsof | grep /tmp/tmptcTxLBtmpfs | awk '{print $1, $2}' | sort -u
cron 32720
root@tina ~ # ls -l /proc/32720/exe
lrwxrwxrwx 1 root root 0 Jun 3 22:40 /proc/32720/exe -> /tmp/tmptcTxLBtmpfs/usr/sbin/cron
root@tina ~ # kill -9 32720
root@tina ~ # tail /var/log/syslog
Jun 3 22:23:44 tina cron[12186]: (CRON) INFO (Skipping @reboot jobs -- not system startup)
Jun 3 22:23:44 tina kernel: [19691.313399] init: cron main process ended, respawning
Jun 3 22:38:27 tina cron[32719]: (CRON) INFO (pidfile fd = 3)
Jun 3 22:38:27 tina cron[32720]: (CRON) STARTUP (fork ok)
Jun 3 22:38:27 tina cron[32720]: (CRON) INFO (Running @reboot jobs)
Jun 3 22:40:35 tina kernel: [20701.709483] init: cron main process (32720) killed by KILL signal
Jun 3 22:40:35 tina kernel: [20701.709515] init: cron main process ended, respawning
Jun 3 22:40:35 tina cron[471]: (CRON) INFO (pidfile fd = 3)
Jun 3 22:40:35 tina cron[472]: (CRON) STARTUP (fork ok)
Jun 3 22:40:35 tina cron[472]: (CRON) INFO (Skipping @reboot jobs -- not system startup)
root@tina ~ # lsb_release -rd
Description: Ubuntu 12.04 LTS
Release: 12.04

Revision history for this message
Chuck Short (zulcss) wrote :

Which version of vmbuilder is this with?

Changed in vm-builder (Ubuntu):
status: New → Incomplete
Revision history for this message
Tokuko (launchpad-net-tokuko) wrote :

This is the version I'm using:
ii python-vm-builder 0.12.4+bzr477-0ubuntu1 VM builder

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Interesting - this would also explain bug 879710.

Why would cron be being started? Does vmbuilder need to do a

cat > "$rootfs/partial-${arch}"/usr/sbin/policy-rc.d << EOF
#!/bin/sh
exit 101
EOF

(Stolen from the ubuntu lxc template and courtesy of stgraber)?

Changed in vm-builder (Ubuntu):
status: Incomplete → Confirmed
importance: Undecided → High
Revision history for this message
Alex Dehnert (adehnert) wrote :

It looks to me like the issue is that while vmbuilder moves away initctl to avoid starting any services, upstart (or maybe another init?) gets reinstalled, replacing the moved initctl. As a result, it leaks a cron invocation. (I'm not totally sure why the policy-rc.d change that's in the guest isn't working --- my assumption is that initctl is contacting Upstart outside the chroot over D-Bus, and that Upstart sees the hosts' /usr/sbin/policy-rc.d. I guess vmbuilder could stash something in that policy-rc.d, but that seems slightly messy.)

I've attached a patch that seems to allow me to build VMs running hardy, lucid, maverick, natty, oneiric, and precise (all amd64; I haven't tested other architectures). The earlier suites are no longer supported, so building those bails pretty quickly...

Revision history for this message
Ubuntu Foundations Team Bug Bot (crichton) wrote :

The attachment "lucid-vm.patch" of this bug report has been identified as being a patch. The ubuntu-reviewers team has been subscribed to the bug report so that they can review the patch. In the event that this is in fact not a patch you can resolve this situation by removing the tag 'patch' from the bug report and editing the attachment so that it is not flagged as a patch. Additionally, if you are member of the ubuntu-reviewers team please also unsubscribe the team from this bug report.

[This is an automated message performed by a Launchpad user owned by Brian Murray. Please contact him regarding any issues with the action taken in this bug report.]

tags: added: patch
Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Thanks, this patch seemed to work for me on quantal, for creating quantal and hardy vms.

Revision history for this message
Serge Hallyn (serge-hallyn) wrote :

Sorry, not quantal, but precise, lucid and hardy.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package vm-builder - 0.12.4+bzr480-0ubuntu1

---------------
vm-builder (0.12.4+bzr480-0ubuntu1) quantal; urgency=low

  * Patch from Alex Dehnert (adehnert) to fix tmpfs unmounting failure
    (LP: #1008225)
  * From Scott Moser: fix vmbuilder --version output (LP: #1003230)
 -- Serge Hallyn <email address hidden> Mon, 23 Jul 2012 23:10:58 -0500

Changed in vm-builder (Ubuntu):
status: Confirmed → Fix Released
Changed in vm-builder (Ubuntu Precise):
importance: Undecided → High
status: New → Triaged
assignee: nobody → Serge Hallyn (serge-hallyn)
description: updated
Changed in vm-builder (Ubuntu Precise):
status: Triaged → In Progress
assignee: Serge Hallyn (serge-hallyn) → nobody
Revision history for this message
Chris Halse Rogers (raof) wrote : Please test proposed package

Hello Tokuko, or anyone else affected,

Accepted vm-builder into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/vm-builder/0.12.4+bzr477-0ubuntu3 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please change the bug tag from verification-needed to verification-done. If it does not, change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Changed in vm-builder (Ubuntu Precise):
status: In Progress → Fix Committed
tags: added: verification-needed
Revision history for this message
Alan Pope 🍺🐧🐱 🦄 (popey) wrote :
Download full text (6.0 KiB)

alan@deep-thought:~$ sudo vmbuilder kvm ubuntu -o -v --tmpfs 1536 --rootsize=4096M --swapsize=512M -d vm1 --proxy=http://192.168.1.2:3128
2012-09-23 21:37:16,702 INFO : Mounting tmpfs under /tmp/tmpyXTs9ntmpfs
2012-09-23 21:37:16,705 INFO : Calling hook: preflight_check
2012-09-23 21:37:16,708 INFO : Calling hook: set_defaults
2012-09-23 21:37:16,708 INFO : Calling hook: bootstrap
2012-09-23 21:58:07,557 INFO : Calling hook: configure_os
2012-09-23 22:00:21,739 INFO :
2012-09-23 22:00:21,739 INFO : Current default time zone: 'Etc/UTC'
2012-09-23 22:00:21,740 INFO : Local time is now: Sun Sep 23 21:00:21 UTC 2012.
2012-09-23 22:00:21,740 INFO : Universal Time is now: Sun Sep 23 21:00:21 UTC 2012.
2012-09-23 22:00:21,740 INFO :
Extracting templates from packages: 100%
2012-09-23 22:14:46,150 INFO :
2012-09-23 22:14:46,151 INFO : Current default time zone: 'Etc/UTC'
2012-09-23 22:14:46,153 INFO : Local time is now: Sun Sep 23 21:14:46 UTC 2012.
2012-09-23 22:14:46,154 INFO : Universal Time is now: Sun Sep 23 21:14:46 UTC 2012.
2012-09-23 22:14:46,154 INFO : Run 'dpkg-reconfigure tzdata' if you wish to change it.
2012-09-23 22:14:46,154 INFO :
2012-09-23 22:14:50,928 INFO : Updating certificates in /etc/ssl/certs... WARNING: Skipping duplicate certificate brasil.gov.br.pem
2012-09-23 22:14:50,928 INFO : 0 added, 1 removed; done.
2012-09-23 22:14:50,933 INFO : Running hooks in /etc/ca-certificates/update.d....done.
2012-09-23 22:14:51,816 INFO :
2012-09-23 22:14:51,816 INFO : Warning: Fake initctl called, doing nothing
2012-09-23 22:15:13,523 INFO : Cleaning up
2012-09-23 22:15:13,523 INFO : Calling hook: preflight_check
2012-09-23 22:15:13,523 INFO : Calling hook: configure_networking
2012-09-23 22:15:13,533 INFO : Calling hook: configure_mounting
2012-09-23 22:15:13,538 INFO : Calling hook: mount_partitions
2012-09-23 22:15:13,539 INFO : Mounting target filesystems
2012-09-23 22:15:13,539 INFO : Creating disk image: "/tmp/tmp83B_ke" of size: 4608MB
2012-09-23 22:15:13,551 INFO : Adding partition table to disk image: /tmp/tmp83B_ke
2012-09-23 22:15:13,899 INFO : Adding type 4 partition to disk image: /tmp/tmp83B_ke
2012-09-23 22:15:13,899 INFO : Partition at beginning of disk - reserving first cylinder
2012-09-23 22:15:14,303 INFO : Adding type 3 partition to disk image: /tmp/tmp83B_ke
2012-09-23 22:15:14,313 INFO : [0] ../../libparted/filesys.c:148 (ped_file_system_type_get): File system alias linux-swap(new) is deprecated
2012-09-23 22:15:14,607 INFO : Creating loop devices corresponding to the created partitions
2012-09-23 22:15:14,620 INFO : Creating file systems
2012-09-23 22:15:14,634 INFO : mke2fs 1.42 (29-Nov-2011)
2012-09-23 22:15:15,033 INFO : mkswap: /dev/mapper/loop0p2: warning: don't erase bootbits sectors
2012-09-23 22:15:15,033 INFO : on whole disk. Use -f to force.
2012-09-23 22:15:17,087 INFO : Calling hook: install_bootloader
2012-09-23 22:16:24,188 INFO : Searching for GRUB installation directory ... found: /boot/grub
2012-09-23 22:16:24,216 INFO : Searching for default file ... Gen...

Read more...

tags: added: verification-done
removed: verification-needed
tags: added: verification-needed
removed: verification-done
Revision history for this message
Alan Pope 🍺🐧🐱 🦄 (popey) wrote :

Oops, left comment on wrong bug, should have left this on bug 966944. Sorry for the noise.

Revision history for this message
Jarl Nicolson (jnicolson) wrote :

I had started getting this error with chroot/dev not unmounting cleanly, caused by the same issue (you could see the extra cron processes running afterwards). This patch looks to have fixed it for me.

Revision history for this message
Brian Murray (brian-murray) wrote :

Jarl-p - do you mean that you are running the version of the package from -proposed and that fixes it for you? Or did you patch your code locally? If you are in fact using the version of vm-builder from -proposed it would be great if you could change the tag from verification-needed to verification-done.

Revision history for this message
Brian Murray (brian-murray) wrote :

The verification of this was trivial enough that I did it myself.

Using python-vm-builder version 0.12.4+bzr477-0ubuntu3 from precise-proposed I did not experience this crash, and I was able to reproduce the crash with the previous version of python-vm-builder (0ubuntu1).

tags: added: verification-done
removed: verification-needed
Revision history for this message
Adam Conrad (adconrad) wrote : Update Released

The verification of this Stable Release Update has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regresssions.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package vm-builder - 0.12.4+bzr477-0ubuntu3

---------------
vm-builder (0.12.4+bzr477-0ubuntu3) precise-proposed; urgency=low

  [ Alex Dehnert ]
  * fix tmpfs unmounting failure (LP: #1008225)

vm-builder (0.12.4+bzr477-0ubuntu2) precise-proposed; urgency=low

  [ Yoann Dubreuil ]
  * Fix proxy support: set up apt proxies before writing sources.list.
    (LP: #966944)
 -- Serge Hallyn <email address hidden> Mon, 06 Aug 2012 16:06:51 -0500

Changed in vm-builder (Ubuntu Precise):
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.