← Back to team overview

openstack team mailing list archive

Re: compute create instance failure

 

On 04/11/2012 10:17 PM, Craig Vyvial wrote:
> I've run into a few issues while i have been testing creating and deleting instances on my vm after setting everything up with devstack. I create a new instance and it goes into an error state. the log says it failed to map partitions but this is the same image i have been using without problems before. its a qcow2 image i created with ubuntu-vmbuilder. 
> 
> Anyone else see this?
> 
> i thought maybe i was out of memory but thats not the case.
> ubuntu@ubuntu:/opt/stack$ df
> Filesystem           1K-blocks      Used Available Use% Mounted on
> /dev/sda1             18578172   7169564  10464892  41% /
> udev                    501644         4    501640   1% /dev
> tmpfs                   203828       324    203504   1% /run
> none                      5120         0      5120   0% /run/lock
> none                    509560         0    509560   0% /run/shm
> 
> Excerpt from the nova-compute logs:
> 
> 2012-04-11 13:54:26 DEBUG nova.virt.libvirt.connection [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Finished toXML method from (pid=2720) to_xml /opt/stack/nova/nova/virt/libvirt/connection.py:1662
> 2012-04-11 13:54:26 INFO nova.virt.libvirt.firewall [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Called setup_basic_filtering in nwfilter
> 2012-04-11 13:54:26 INFO nova.virt.libvirt.firewall [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Ensuring static filters
> 2012-04-11 13:54:26 DEBUG nova.virt.firewall [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Filters added to instance 939d3af8-e7bd-4d4b-b026-c20097e207a6 from (pid=2720) prepare_instance_filter /opt/stack/nova/nova/virt/firewall.py:137
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab semaphore "iptables" for method "_do_refresh_provider_fw_rules"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:929
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got semaphore "iptables" for method "_do_refresh_provider_fw_rules"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:933
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab file lock "iptables" for method "_do_refresh_provider_fw_rules"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:937
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got file lock "iptables" for method "_do_refresh_provider_fw_rules"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:944
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab semaphore "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:929
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got semaphore "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:933
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab file lock "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:937
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got file lock "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:944
> 2012-04-11 13:54:26 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-save -t filter from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-restore from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-save -t nat from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-restore from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.network.linux_net [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] IPTablesManager.apply completed with success from (pid=2720) apply /opt/stack/nova/nova/network/linux_net.py:335
> 2012-04-11 13:54:27 DEBUG nova.virt.firewall [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Provider Firewall Rules refreshed from (pid=2720) prepare_instance_filter /opt/stack/nova/nova/virt/firewall.py:139
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab semaphore "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:929
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got semaphore "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:933
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab file lock "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:937
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got file lock "iptables" for method "apply"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:944
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-save -t filter from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-restore from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-save -t nat from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap iptables-restore from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 DEBUG nova.network.linux_net [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] IPTablesManager.apply completed with success from (pid=2720) apply /opt/stack/nova/nova/network/linux_net.py:335
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): mkdir -p /opt/stack/nova/instances/instance-00000008/ from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:27 INFO nova.virt.libvirt.connection [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Creating image
> 2012-04-11 13:54:27 DEBUG nova.virt.libvirt.connection [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] block_device_list [u'vdb'] from (pid=2720) _volume_in_mapping /opt/stack/nova/nova/virt/libvirt/connection.py:1381
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab semaphore "fe8b1ce5a3190061745dac1e142977134a537d3f" for method "call_if_not_exists"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:929
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got semaphore "fe8b1ce5a3190061745dac1e142977134a537d3f" for method "call_if_not_exists"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:933
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Attempting to grab semaphore "/opt/stack/nova/instances/_base/fe8b1ce5a3190061745dac1e142977134a537d3f" for method "copy_and_extend"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:929
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Got semaphore "/opt/stack/nova/instances/_base/fe8b1ce5a3190061745dac1e142977134a537d3f" for method "copy_and_extend"... from (pid=2720) inner /opt/stack/nova/nova/utils.py:933
> 2012-04-11 13:54:27 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): qemu-img create -f qcow2 -o cluster_size=2M,backing_file=/opt/stack/nova/instances/_base/fe8b1ce5a3190061745dac1e142977134a537d3f /opt/stack/nova/instances/instance-00000008/disk from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:28 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap qemu-nbd -c /dev/nbd15 /opt/stack/nova/instances/instance-00000008/disk from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap kpartx -a /dev/nbd15 from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap qemu-nbd -d /dev/nbd15 from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:29 DEBUG nova.virt.disk.api [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Failed to map partitions: no partitions found from (pid=2720) mount /opt/stack/nova/nova/virt/disk/api.py:205
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap guestmount --rw -a /opt/stack/nova/instances/instance-00000008/disk -m /dev/sda1 /tmp/tmppBPJDz from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Result was 1 from (pid=2720) execute /opt/stack/nova/nova/utils.py:236
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Unexpected error while running command.
> Command: sudo /usr/local/bin/nova-rootwrap guestmount --rw -a /opt/stack/nova/instances/instance-00000008/disk -m /dev/sda1 /tmp/tmppBPJDz
> Exit code: 1
> Stdout: ''
> Stderr: 'Traceback (most recent call last):\n  File "/usr/local/bin/nova-rootwrap", line 7, in <module>\n    execfile(__file__)\n  File "/opt/stack/nova/bin/nova-rootwrap", line 69, in <module>\n    env=filtermatch.get_environment(userargs))\n  File "/usr/lib/python2.7/subprocess.py", line 679, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1239, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n' from (pid=2720) trycmd /opt/stack/nova/nova/utils.py:278
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap fusermount -u /tmp/tmppBPJDz from (pid=2720) execute /opt/stack/nova/nova/utils.py:220
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Result was 1 from (pid=2720) execute /opt/stack/nova/nova/utils.py:236
> 2012-04-11 13:54:29 DEBUG nova.utils [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Unexpected error while running command.
> Command: sudo /usr/local/bin/nova-rootwrap fusermount -u /tmp/tmppBPJDz
> Exit code: 1
> Stdout: ''
> Stderr: '/bin/fusermount: failed to unmount /tmp/tmppBPJDz: Invalid argument\n' from (pid=2720) trycmd /opt/stack/nova/nova/utils.py:278
> 2012-04-11 13:54:29 DEBUG nova.virt.disk.api [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Failed to mount filesystem: Unexpected error while running command.
> Command: sudo /usr/local/bin/nova-rootwrap guestmount --rw -a /opt/stack/nova/instances/instance-00000008/disk -m /dev/sda1 /tmp/tmppBPJDz
> Exit code: 1
> Stdout: ''
> Stderr: 'Traceback (most recent call last):\n  File "/usr/local/bin/nova-rootwrap", line 7, in <module>\n    execfile(__file__)\n  File "/opt/stack/nova/bin/nova-rootwrap", line 69, in <module>\n    env=filtermatch.get_environment(userargs))\n  File "/usr/lib/python2.7/subprocess.py", line 679, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1239, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n' from (pid=2720) mount /opt/stack/nova/nova/virt/disk/api.py:205
> 2012-04-11 13:54:29 ERROR nova.compute.manager [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Instance failed to spawn
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Traceback (most recent call last):
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/compute/manager.py", line 592, in _spawn
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     self._legacy_nw_info(network_info), block_device_info)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/exception.py", line 114, in wrapped
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     return f(*args, **kw)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 893, in spawn
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     block_device_info=block_device_info)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 1364, in _create_image
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     partition=target_partition)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 935, in _inject_files
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     use_cow=FLAGS.use_cow_images)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]   File "/opt/stack/nova/nova/virt/disk/api.py", line 258, in inject_files
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6]     raise exception.Error(img.errors)
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Error: 
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] --
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Failed to map partitions: no partitions found
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] --
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Failed to mount filesystem: Unexpected error while running command.
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Command: sudo /usr/local/bin/nova-rootwrap guestmount --rw -a /opt/stack/nova/instances/instance-00000008/disk -m /dev/sda1 /tmp/tmppBPJDz
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Exit code: 1
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Stdout: ''
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Stderr: 'Traceback (most recent call last):\n  File "/usr/local/bin/nova-rootwrap", line 7, in <module>\n    execfile(__file__)\n  File "/opt/stack/nova/bin/nova-rootwrap", line 69, in <module>\n    env=filtermatch.get_environment(userargs))\n  File "/usr/lib/python2.7/subprocess.py", line 679, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1239, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n'
> 2012-04-11 13:54:29 TRACE nova.compute.manager [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] 
> 2012-04-11 13:54:29 DEBUG nova.compute.manager [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] [instance: 939d3af8-e7bd-4d4b-b026-c20097e207a6] Deallocating network for instance from (pid=2720) _deallocate_network /opt/stack/nova/nova/compute/manager.py:616
> 2012-04-11 13:54:29 DEBUG nova.rpc.amqp [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Making asynchronous cast on network... from (pid=2720) cast /opt/stack/nova/nova/rpc/amqp.py:343
> 2012-04-11 13:54:30 ERROR nova.rpc.amqp [req-91b3855a-1f90-42bb-8c24-6bf546aed826 2e11238b4cf444ba8dcf321a98764050 cb0ad32733bb4366962ba76033f4b6fb] Exception during message handling
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Traceback (most recent call last):
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/rpc/amqp.py", line 247, in _process_data
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     rval = node_func(context=ctxt, **node_args)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 114, in wrapped
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     return f(*args, **kw)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 177, in decorated_function
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     sys.exc_info())
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self.gen.next()
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 171, in decorated_function
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     return function(self, context, instance_uuid, *args, **kwargs)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 651, in run_instance
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     do_run_instance()
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/utils.py", line 947, in inner
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     retval = f(*args, **kwargs)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 650, in do_run_instance
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self._run_instance(context, instance_uuid, **kwargs)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 451, in _run_instance
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self._set_instance_error_state(context, instance_uuid)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self.gen.next()
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 432, in _run_instance
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self._deallocate_network(context, instance)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self.gen.next()
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 429, in _run_instance
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     injected_files, admin_password)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 592, in _spawn
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     self._legacy_nw_info(network_info), block_device_info)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 114, in wrapped
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     return f(*args, **kw)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 893, in spawn
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     block_device_info=block_device_info)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 1364, in _create_image
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     partition=target_partition)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/virt/libvirt/connection.py", line 935, in _inject_files
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     use_cow=FLAGS.use_cow_images)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp   File "/opt/stack/nova/nova/virt/disk/api.py", line 258, in inject_files
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp     raise exception.Error(img.errors)
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Error: 
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp --
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Failed to map partitions: no partitions found
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp --
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Failed to mount filesystem: Unexpected error while running command.
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Command: sudo /usr/local/bin/nova-rootwrap guestmount --rw -a /opt/stack/nova/instances/instance-00000008/disk -m /dev/sda1 /tmp/tmppBPJDz
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Exit code: 1
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Stdout: ''
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp Stderr: 'Traceback (most recent call last):\n  File "/usr/local/bin/nova-rootwrap", line 7, in <module>\n    execfile(__file__)\n  File "/opt/stack/nova/bin/nova-rootwrap", line 69, in <module>\n    env=filtermatch.get_environment(userargs))\n  File "/usr/lib/python2.7/subprocess.py", line 679, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1239, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n'
> 2012-04-11 13:54:30 TRACE nova.rpc.amqp 
> 2012-04-11 13:55:26 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=2720) periodic_tasks /opt/stack/nova/nova/manager.py:152

Note you just get a warning when failing to inject any of
  (key, net, metadata, admin_password)

However if you've specified "injected_files" you'll get
the presented exception on error.

Now even though the specific error here is about guestmount being missing,
just installing guestmount may not work unless the partition
to inject to is "/dev/sda1". That's probably not the case, or otherwise
the nbd method would have worked.  OpenStack is currently hardcoded
to inject to the first partition.  Now you could have a complicated or
arbitrary image layout with volume groups etc. so to get guestmount to
inspect the image, and find the partition to inject you'd need to:

Edit /usr/lib/.../nova/virt/disk/guestfs.py
Add this line to the start of the mnt_dev() function:
  partition = -1
Restart the nova compute service.

I'll prepare an upstream patch to make this configurable.

cheers,
Pádraig.


Follow ups

References