Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

When creating an instance from a specific image, I get a failure.

I have a certain image (Oracle Linux with some applications on it) that I've been creating instances from for the past few weeks. A couple of days ago, creating instances from that images began failing repeatedly, while creating instances from another image does seem to work (the main difference between the two images, as far as I can tell is that the failing one comes with cloud-init installed, and the working one doesn't).

At the moment I'm testing this with the Horizon UI, simply trying to create an instance.

I looked at the nova compute.log on the compute node and I see an exception (pasted at the end) basically saying

Instance failed to spawn

I'm not sure what is the cause for this - first I'm not sure what might cause this, and second, what changed - I know that the image hasn't changed, and I don't remember making any modifications to the configuration files that may have caused this.

Is there a good way to analyze this issue - some way to access boot logs, see what happened while the instance tried to spawn and failed?

I tried opening debug logs, but couldn't find something that looks meaningful W.R.T. why this failure occurs.

I'd appreciate any help!

Thanks. Avi

Full log (Can't upload yet, newbie):

2014-05-29 13:05:15.320 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-05-29 13:05:15.877 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:05:37.657 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Starting instance...
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Attempting claim: memory 4096 MB, disk 20 GB, VCPUs 2
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Memory: 258468 MB, used: 29184.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Memory limit: 387702.00 MB, free: 358518.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Disk: 3790 GB, used: 140.00 GB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Disk limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total CPU: 32 VCPUs, used: 14.00 VCPUs
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] CPU limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Claim successful
2014-05-29 13:05:38.491 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Creating image
2014-05-29 13:05:39.783 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Injecting key into image 8a2fa109-b984-4ca7-9166-ffebfd7b52fc
2014-05-29 13:05:40.222 29768 WARNING nova.virt.disk.vfs.guestfs [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Failed to close augeas aug_close: call launch before using this function\n(in guestfish, don't forget to use the 'run' command)
2014-05-29 13:05:40.228 29768 WARNING nova.virt.disk.api [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Ignoring error injecting data into image (Error mounting /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk with libguestfs (guestfs_launch failed.
See http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
and/or run 'libguestfs-test-tool'.))
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Called setup_basic_filtering in nwfilter
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Ensuring static filters
2014-05-29 13:05:41.864 29768 ERROR nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] An error occurred while trying to launch a defined domain with xml: <domain type='kvm'>
  <name>instance-000000e3</name>
  <uuid>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat Inc.</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2013.2.3-1.el6</entry>
      <entry name='serial'>e00d6db6-0010-ffff-ffff-ffffff200008</entry>
      <entry name='uuid'>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:12:b6:c8'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-000000e3-fa163e12b6c8'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:05:41.942 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Terminating instance
2014-05-29 13:05:42.178 29768 INFO nova.virt.libvirt.driver [-] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance destroyed successfully.
2014-05-29 13:05:42.724 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deleting instance files /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d
2014-05-29 13:05:42.725 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deletion of /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d complete
2014-05-29 13:05:43.356 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Error: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1043, in _build_instance
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     set_access_ip=set_access_ip)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1426, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     LOG.exception(_('Instance failed to spawn'), instance=instance)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:06:15.961 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:06:16.543 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:07:16.775 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:07:17.302 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:07:17.344 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:08:17.560 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:08:18.055 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16

When creating an instance from a specific image, I get a failure.

I have a certain image (Oracle Linux with some applications on it) that I've been creating instances from for the past few weeks. A couple of days ago, creating instances from that images began failing repeatedly, while creating instances from another image does seem to work (the main difference between the two images, as far as I can tell is that the failing one comes with cloud-init installed, and the working one doesn't).

At the moment I'm testing this with the Horizon UI, simply trying to create an instance.

I looked at the nova compute.log on the compute node and I see an exception (pasted at the end) basically saying

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn

I'm not sure what is the cause for this - first I'm not sure what might cause this, and second, what changed - I know that the image hasn't changed, and I don't remember making any modifications to the configuration files that may have caused this.

Is there a good way to analyze this issue - some way to access boot logs, see what happened while the instance tried to spawn and failed?

I tried opening debug logs, but couldn't find something that looks meaningful W.R.T. why this failure occurs.

Here is some more information about my installation:

Using Openstack Havana (glance, keystone, horizon, nova, heat and ceilometer), split between controller and compute node. The controller node doesn't have the nova-compute service enabled, so all instances are created on the compute node.

Regarding the images - I have a few images, all in qcow2 format (created them in virtual box). All but two of them seem to be working fine - I can create instances from them, and the other two, basically the same image, are the ones I'm having problems with.

The image contents in all cases is Oracle Linux (Basically RHEL), with a Weblogic application installed on them. The images that are working are those without cloud-init on them, and the ones that don't are the ones without.

I'd appreciate any help!

Thanks. Avi

Full Libvirt instance log:

2014-05-29 11:46:32.956+0000: starting up LC_ALL=C PATH=/sbin:/usr/sbin:/bin:/usr/bin QEMU_AUDIO_DRV=none /usr/libexec/qemu-kvm -name instance-000000e7 -S -M rhel6.5.0 -cpu SandyBridge,+pdpe1gb,+osxsave,+dca,+pcid,+pdcm,+xtpr,+tm2,+est,+smx,+vmx,+ds_cpl,+monitor,+dtes64,+pbe,+tm,+ht,+ss,+acpi,+ds,+vme -enable-kvm -m 4096 -realtime mlock=off -smp 2,sockets=2,cores=1,threads=1 -uuid a487b3e2-4ae2-47e1-b596-0e919b049399 -smbios type=1,manufacturer=Red Hat Inc.,product=OpenStack Nova,version=2013.2.3-1.el6,serial=e00d6db6-0010-ffff-ffff-ffffff200008,uuid=a487b3e2-4ae2-47e1-b596-0e919b049399 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-000000e7.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -no-kvm-pit-reinjection -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=27,id=hostnet0,vhost=on,vhostfd=32 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:c1:53:56,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/console.log -device isa-serial,chardev=charserial0,id=serial0 -chardev pty,id=charserial1 -device isa-serial,chardev=charserial1,id=serial1 -device usb-tablet,id=input0 -vnc 0.0.0.0:5 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 char device redirected to /dev/pts/8 qemu-kvm: -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none: could not open disk image /home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk: Operation not supported 2014-05-29 11:46:33.338+0000: shutting down

/var/log/libvirt/libvirtd.log:

2014-05-29 11:46:33.338+0000: 2730: error : qemuMonitorIORead:514 : Unable to read from monitor: Connection reset by peer 2014-05-29 11:46:33.338+0000: 2734: error : virNWFilterDHCPSnoopEnd:2131 : internal error ifname "vnet5" not in key map 2014-05-29 11:46:33.356+0000: 2734: error : virNetDevGetIndex:653 : Unable to get index for interface vnet5: No such device

Nova compute log (Can't upload yet, newbie):

2014-05-29 13:05:15.320 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-05-29 13:05:15.877 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:05:37.657 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Starting instance...
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Attempting claim: memory 4096 MB, disk 20 GB, VCPUs 2
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Memory: 258468 MB, used: 29184.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Memory limit: 387702.00 MB, free: 358518.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Disk: 3790 GB, used: 140.00 GB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Disk limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total CPU: 32 VCPUs, used: 14.00 VCPUs
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] CPU limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Claim successful
2014-05-29 13:05:38.491 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Creating image
2014-05-29 13:05:39.783 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Injecting key into image 8a2fa109-b984-4ca7-9166-ffebfd7b52fc
2014-05-29 13:05:40.222 29768 WARNING nova.virt.disk.vfs.guestfs [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Failed to close augeas aug_close: call launch before using this function\n(in guestfish, don't forget to use the 'run' command)
2014-05-29 13:05:40.228 29768 WARNING nova.virt.disk.api [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Ignoring error injecting data into image (Error mounting /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk with libguestfs (guestfs_launch failed.
See http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
and/or run 'libguestfs-test-tool'.))
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Called setup_basic_filtering in nwfilter
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Ensuring static filters
2014-05-29 13:05:41.864 29768 ERROR nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] An error occurred while trying to launch a defined domain with xml: <domain type='kvm'>
  <name>instance-000000e3</name>
  <uuid>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat Inc.</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2013.2.3-1.el6</entry>
      <entry name='serial'>e00d6db6-0010-ffff-ffff-ffffff200008</entry>
      <entry name='uuid'>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:12:b6:c8'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-000000e3-fa163e12b6c8'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:05:41.942 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Terminating instance
2014-05-29 13:05:42.178 29768 INFO nova.virt.libvirt.driver [-] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance destroyed successfully.
2014-05-29 13:05:42.724 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deleting instance files /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d
2014-05-29 13:05:42.725 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deletion of /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d complete
2014-05-29 13:05:43.356 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Error: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1043, in _build_instance
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     set_access_ip=set_access_ip)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1426, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     LOG.exception(_('Instance failed to spawn'), instance=instance)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:06:15.961 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:06:16.543 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:07:16.775 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:07:17.302 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:07:17.344 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:08:17.560 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:08:18.055 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16

When creating an instance from a specific image, I get a failure.

I have a certain image (Oracle Linux with some applications on it) that I've been creating instances from for the past few weeks. A couple of days ago, creating instances from that images began failing repeatedly, while creating instances from another image does seem to work (the main difference between the two images, as far as I can tell is that the failing one comes with cloud-init installed, and the working one doesn't).

At the moment I'm testing this with the Horizon UI, simply trying to create an instance.

I looked at the nova compute.log on the compute node and I see an exception (pasted at the end) basically saying

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn

I'm not sure what is the cause for this - first I'm not sure what might cause this, and second, what changed - I know that the image hasn't changed, and I don't remember making any modifications to the configuration files that may have caused this.

Is there a good way to analyze this issue - some way to access boot logs, see what happened while the instance tried to spawn and failed?

I tried opening debug logs, but couldn't find something that looks meaningful W.R.T. why this failure occurs.

Here is some more information about my installation:

Using Openstack Havana (glance, keystone, horizon, nova, heat and ceilometer), split between controller and compute node. The controller node doesn't have the nova-compute service enabled, so all instances are created on the compute node.

Regarding the images - I have a few images, all in qcow2 format (created them in virtual box). All but two of them seem to be working fine - I can create instances from them, and the other two, basically the same image, are the ones I'm having problems with.

The image contents in all cases is Oracle Linux (Basically RHEL), with a Weblogic application installed on them. The images that are working are those without cloud-init on them, and the ones that don't are the ones without.

I'd appreciate any help!

Thanks. Avi

Libvirt instance log:

2014-05-29 11:46:32.956+0000: starting up
LC_ALL=C PATH=/sbin:/usr/sbin:/bin:/usr/bin QEMU_AUDIO_DRV=none /usr/libexec/qemu-kvm -name instance-000000e7 -S -M rhel6.5.0 -cpu SandyBridge,+pdpe1gb,+osxsave,+dca,+pcid,+pdcm,+xtpr,+tm2,+est,+smx,+vmx,+ds_cpl,+monitor,+dtes64,+pbe,+tm,+ht,+ss,+acpi,+ds,+vme -enable-kvm -m 4096 -realtime mlock=off -smp 2,sockets=2,cores=1,threads=1 -uuid a487b3e2-4ae2-47e1-b596-0e919b049399 -smbios type=1,manufacturer=Red Hat Inc.,product=OpenStack Nova,version=2013.2.3-1.el6,serial=e00d6db6-0010-ffff-ffff-ffffff200008,uuid=a487b3e2-4ae2-47e1-b596-0e919b049399 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-000000e7.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -no-kvm-pit-reinjection -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=27,id=hostnet0,vhost=on,vhostfd=32 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:c1:53:56,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/console.log -device isa-serial,chardev=charserial0,id=serial0 -chardev pty,id=charserial1 -device isa-serial,chardev=charserial1,id=serial1 -device usb-tablet,id=input0 -vnc 0.0.0.0:5 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5
char device redirected to /dev/pts/8
qemu-kvm: -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none: could not open disk image /home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk: Operation not supported
2014-05-29 11:46:33.338+0000: shutting down

down

/var/log/libvirt/libvirtd.log:

2014-05-29 11:46:33.338+0000: 2730: error : qemuMonitorIORead:514 : Unable to read from monitor: Connection reset by peer
2014-05-29 11:46:33.338+0000: 2734: error : virNWFilterDHCPSnoopEnd:2131 : internal error ifname "vnet5" not in key map
2014-05-29 11:46:33.356+0000: 2734: error : virNetDevGetIndex:653 : Unable to get index for interface vnet5: No such device

device

Nova compute log (Can't upload yet, newbie):

2014-05-29 13:05:15.320 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-05-29 13:05:15.877 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:05:37.657 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Starting instance...
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Attempting claim: memory 4096 MB, disk 20 GB, VCPUs 2
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Memory: 258468 MB, used: 29184.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Memory limit: 387702.00 MB, free: 358518.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Disk: 3790 GB, used: 140.00 GB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Disk limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total CPU: 32 VCPUs, used: 14.00 VCPUs
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] CPU limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Claim successful
2014-05-29 13:05:38.491 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Creating image
2014-05-29 13:05:39.783 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Injecting key into image 8a2fa109-b984-4ca7-9166-ffebfd7b52fc
2014-05-29 13:05:40.222 29768 WARNING nova.virt.disk.vfs.guestfs [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Failed to close augeas aug_close: call launch before using this function\n(in guestfish, don't forget to use the 'run' command)
2014-05-29 13:05:40.228 29768 WARNING nova.virt.disk.api [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Ignoring error injecting data into image (Error mounting /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk with libguestfs (guestfs_launch failed.
See http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
and/or run 'libguestfs-test-tool'.))
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Called setup_basic_filtering in nwfilter
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Ensuring static filters
2014-05-29 13:05:41.864 29768 ERROR nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] An error occurred while trying to launch a defined domain with xml: <domain type='kvm'>
  <name>instance-000000e3</name>
  <uuid>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat Inc.</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2013.2.3-1.el6</entry>
      <entry name='serial'>e00d6db6-0010-ffff-ffff-ffffff200008</entry>
      <entry name='uuid'>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:12:b6:c8'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-000000e3-fa163e12b6c8'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:05:41.942 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Terminating instance
2014-05-29 13:05:42.178 29768 INFO nova.virt.libvirt.driver [-] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance destroyed successfully.
2014-05-29 13:05:42.724 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deleting instance files /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d
2014-05-29 13:05:42.725 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deletion of /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d complete
2014-05-29 13:05:43.356 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Error: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1043, in _build_instance
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     set_access_ip=set_access_ip)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1426, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     LOG.exception(_('Instance failed to spawn'), instance=instance)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:06:15.961 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:06:16.543 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:07:16.775 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:07:17.302 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:07:17.344 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:08:17.560 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:08:18.055 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16

When creating an instance from a specific image, I get a failure.

I have a certain image (Oracle Linux with some applications on it) that I've been creating instances from for the past few weeks. A couple of days ago, creating instances from that images began failing repeatedly, while creating instances from another image does seem to work (the main difference between the two images, as far as I can tell is that the failing one comes with cloud-init installed, and the working one doesn't).

At the moment I'm testing this with the Horizon UI, simply trying to create an instance.

I looked at the nova compute.log on the compute node and I see an exception (pasted at the end) basically saying

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn

I'm not sure what is the cause for this - first I'm not sure what might cause this, and second, what changed - I know that the image hasn't changed, and I don't remember making any modifications to the configuration files that may have caused this.

Is there a good way to analyze this issue - some way to access boot logs, see what happened while the instance tried to spawn and failed?

I tried opening debug logs, but couldn't find something that looks meaningful W.R.T. why this failure occurs.

Here is some more information about my installation:

Using Openstack Havana (glance, keystone, horizon, nova, heat and ceilometer), split between controller and compute node. The controller node doesn't have the nova-compute service enabled, so all instances are created on the compute node.

Regarding the images - I have a few images, all in qcow2 format (created them in virtual box). All but two of them seem to be working fine - I can create instances from them, and the other two, basically the same image, are the ones I'm having problems with.

The image contents in all cases is Oracle Linux (Basically RHEL), with a Weblogic application installed on them. The images that are working are those without cloud-init on them, and the ones that don't are the ones without.

I'd appreciate any help!

Thanks. Avi

Libvirt instance log:

2014-05-29 11:46:32.956+0000: starting up
LC_ALL=C PATH=/sbin:/usr/sbin:/bin:/usr/bin QEMU_AUDIO_DRV=none /usr/libexec/qemu-kvm -name instance-000000e7 -S -M rhel6.5.0 -cpu SandyBridge,+pdpe1gb,+osxsave,+dca,+pcid,+pdcm,+xtpr,+tm2,+est,+smx,+vmx,+ds_cpl,+monitor,+dtes64,+pbe,+tm,+ht,+ss,+acpi,+ds,+vme -enable-kvm -m 4096 -realtime mlock=off -smp 2,sockets=2,cores=1,threads=1 -uuid a487b3e2-4ae2-47e1-b596-0e919b049399 -smbios type=1,manufacturer=Red Hat Inc.,product=OpenStack Nova,version=2013.2.3-1.el6,serial=e00d6db6-0010-ffff-ffff-ffffff200008,uuid=a487b3e2-4ae2-47e1-b596-0e919b049399 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-000000e7.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -no-kvm-pit-reinjection -no-shutdown -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=27,id=hostnet0,vhost=on,vhostfd=32 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:c1:53:56,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/console.log -device isa-serial,chardev=charserial0,id=serial0 -chardev pty,id=charserial1 -device isa-serial,chardev=charserial1,id=serial1 -device usb-tablet,id=input0 -vnc 0.0.0.0:5 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5
char device redirected to /dev/pts/8
qemu-kvm: -drive file=/home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk,if=none,id=drive-virtio-disk0,format=qcow2,cache=none: could not open disk image /home/nova/instances/a487b3e2-4ae2-47e1-b596-0e919b049399/disk: Operation not supported
2014-05-29 11:46:33.338+0000: shutting down

/var/log/libvirt/libvirtd.log:

2014-05-29 11:46:33.338+0000: 2730: error : qemuMonitorIORead:514 : Unable to read from monitor: Connection reset by peer
2014-05-29 11:46:33.338+0000: 2734: error : virNWFilterDHCPSnoopEnd:2131 : internal error ifname "vnet5" not in key map
2014-05-29 11:46:33.356+0000: 2734: error : virNetDevGetIndex:653 : Unable to get index for interface vnet5: No such device

Nova compute log (Can't upload yet, newbie):

2014-05-29 13:05:15.320 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-05-29 13:05:15.834 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-05-29 13:05:15.877 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:05:37.657 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Starting instance...
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Attempting claim: memory 4096 MB, disk 20 GB, VCPUs 2
2014-05-29 13:05:37.988 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Memory: 258468 MB, used: 29184.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Memory limit: 387702.00 MB, free: 358518.00 MB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total Disk: 3790 GB, used: 140.00 GB
2014-05-29 13:05:37.989 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Disk limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Total CPU: 32 VCPUs, used: 14.00 VCPUs
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] CPU limit not specified, defaulting to unlimited
2014-05-29 13:05:37.990 29768 AUDIT nova.compute.claims [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Claim successful
2014-05-29 13:05:38.491 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Creating image
2014-05-29 13:05:39.783 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Injecting key into image 8a2fa109-b984-4ca7-9166-ffebfd7b52fc
2014-05-29 13:05:40.222 29768 WARNING nova.virt.disk.vfs.guestfs [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Failed to close augeas aug_close: call launch before using this function\n(in guestfish, don't forget to use the 'run' command)
2014-05-29 13:05:40.228 29768 WARNING nova.virt.disk.api [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Ignoring error injecting data into image (Error mounting /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk with libguestfs (guestfs_launch failed.
See http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
and/or run 'libguestfs-test-tool'.))
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Called setup_basic_filtering in nwfilter
2014-05-29 13:05:40.397 29768 INFO nova.virt.libvirt.firewall [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Ensuring static filters
2014-05-29 13:05:41.864 29768 ERROR nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] An error occurred while trying to launch a defined domain with xml: <domain type='kvm'>
  <name>instance-000000e3</name>
  <uuid>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat Inc.</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2013.2.3-1.el6</entry>
      <entry name='serial'>e00d6db6-0010-ffff-ffff-ffffff200008</entry>
      <entry name='uuid'>da98e52e-d8c1-43a0-b4c3-533e88b7f95d</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:12:b6:c8'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-000000e3-fa163e12b6c8'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2014-05-29 13:05:41.865 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance failed to spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:41.865 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:05:41.942 29768 AUDIT nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Terminating instance
2014-05-29 13:05:42.178 29768 INFO nova.virt.libvirt.driver [-] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Instance destroyed successfully.
2014-05-29 13:05:42.724 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deleting instance files /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d
2014-05-29 13:05:42.725 29768 INFO nova.virt.libvirt.driver [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Deletion of /home/nova/instances/da98e52e-d8c1-43a0-b4c3-533e88b7f95d complete
2014-05-29 13:05:43.356 29768 ERROR nova.compute.manager [req-edd9d436-b48a-49ee-9dbd-fe40d7bef362 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Error: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] Traceback (most recent call last):
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1043, in _build_instance
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     set_access_ip=set_access_ip)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1426, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     LOG.exception(_('Instance failed to spawn'), instance=instance)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     block_device_info, context=context)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.XMLDesc(0))
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     domain.createWithFlags(launch_flags)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = execute(f,*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     rv = meth(*args,**kwargs)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] libvirtError: Unable to read from monitor: Connection reset by peer
2014-05-29 13:05:43.356 29768 TRACE nova.compute.manager [instance: da98e52e-d8c1-43a0-b4c3-533e88b7f95d] 
2014-05-29 13:06:15.961 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:06:16.494 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:06:16.543 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:07:16.775 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:07:17.301 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:07:17.302 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-05-29 13:07:17.344 29768 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-05-29 13:08:17.560 29768 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-05-29 13:08:18.055 29768 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-05-29 13:08:18.056 29768 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16

Adding another log with more lines before the error occurs:

2014-06-01 07:39:08.441 11059 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:39:08.971 11059 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:39:08.972 11059 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:39:08.972 11059 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:39:09.018 11059 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:39:28.533 11059 INFO nova.openstack.common.service [-] Caught SIGTERM, exiting
2014-06-01 07:39:30.175 19892 INFO nova.openstack.common.periodic_task [-] Skipping periodic task _periodic_update_dns because its interval is negative
2014-06-01 07:39:30.217 19892 INFO nova.virt.driver [-] Loading compute driver 'libvirt.LibvirtDriver'
2014-06-01 07:39:30.287 19892 INFO nova.openstack.common.rpc.impl_qpid [req-d57cd41a-daab-4fae-a364-b1c3e37cb417 None None] Connected to AMQP server on controller:5672
2014-06-01 07:39:30.297 19892 INFO nova.openstack.common.rpc.impl_qpid [req-d57cd41a-daab-4fae-a364-b1c3e37cb417 None None] Connected to AMQP server on controller:5672
2014-06-01 07:39:30.335 19892 AUDIT nova.service [-] Starting compute node (version 2013.2.3-1.el6)
2014-06-01 07:39:30.541 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: a3ca4fee-3e83-486e-be03-936c3251cd2b] Called setup_basic_filtering in nwfilter
2014-06-01 07:39:30.542 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: a3ca4fee-3e83-486e-be03-936c3251cd2b] Ensuring static filters
2014-06-01 07:39:31.345 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 4026b179-bb28-4f9d-8a10-86a3d351e777] Called setup_basic_filtering in nwfilter
2014-06-01 07:39:31.351 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 4026b179-bb28-4f9d-8a10-86a3d351e777] Ensuring static filters
2014-06-01 07:39:31.667 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 31a5f268-5cdc-4e67-9624-4d533bde33cb] Called setup_basic_filtering in nwfilter
2014-06-01 07:39:31.667 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 31a5f268-5cdc-4e67-9624-4d533bde33cb] Ensuring static filters
2014-06-01 07:39:31.985 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 7f926125-805f-48e3-8ea1-346826fac6ff] Called setup_basic_filtering in nwfilter
2014-06-01 07:39:31.986 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 7f926125-805f-48e3-8ea1-346826fac6ff] Ensuring static filters
2014-06-01 07:39:32.296 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 311b8e93-ba32-41c1-9fc8-3d36651ab937] Called setup_basic_filtering in nwfilter
2014-06-01 07:39:32.297 19892 INFO nova.virt.libvirt.firewall [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] [instance: 311b8e93-ba32-41c1-9fc8-3d36651ab937] Ensuring static filters
2014-06-01 07:39:33.061 19892 AUDIT nova.compute.resource_tracker [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Auditing locally available compute resources
2014-06-01 07:39:33.546 19892 AUDIT nova.compute.resource_tracker [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Free ram (MB): 229284
2014-06-01 07:39:33.546 19892 AUDIT nova.compute.resource_tracker [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Free disk (GB): 3650
2014-06-01 07:39:33.546 19892 AUDIT nova.compute.resource_tracker [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Free VCPUS: 18
2014-06-01 07:39:33.692 19892 INFO nova.compute.resource_tracker [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:39:33.724 19892 INFO nova.openstack.common.rpc.impl_qpid [req-9a5c00b2-a4b1-44de-9b60-d23f52bdbd50 None None] Connected to AMQP server on controller:5672
2014-06-01 07:40:15.764 19892 AUDIT nova.compute.resource_tracker [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Auditing locally available compute resources
2014-06-01 07:40:16.267 19892 AUDIT nova.compute.resource_tracker [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Free ram (MB): 229284
2014-06-01 07:40:16.267 19892 AUDIT nova.compute.resource_tracker [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Free disk (GB): 3650
2014-06-01 07:40:16.267 19892 AUDIT nova.compute.resource_tracker [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Free VCPUS: 18
2014-06-01 07:40:16.313 19892 INFO nova.compute.resource_tracker [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:40:16.397 19892 WARNING nova.compute.manager [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Found 7 in the database and 5 on the hypervisor.
2014-06-01 07:40:16.669 19892 INFO nova.compute.manager [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] [instance: 0b2513a1-80a9-4bee-84eb-ba207217a082] During sync_power_state the instance has a pending task. Skip.
2014-06-01 07:40:16.669 19892 INFO nova.compute.manager [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] [instance: bfa190e2-8095-40ea-a4af-bb17e5829815] During sync_power_state the instance has a pending task. Skip.
2014-06-01 07:40:16.670 19892 INFO nova.compute.manager [req-b1dfcdaf-860a-41f7-8187-162ecd29a431 None None] Updating bandwidth usage cache
2014-06-01 07:41:16.943 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:41:17.452 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:41:17.452 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:41:17.452 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:41:17.494 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:42:17.698 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:42:18.194 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:42:18.194 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:42:18.194 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:42:18.236 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:43:18.446 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:43:18.945 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:43:18.946 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:43:18.946 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:43:18.988 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:44:19.205 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:44:19.694 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:44:19.694 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:44:19.694 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:44:19.736 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:44:30.240 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:44:30.733 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:44:30.733 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:44:30.733 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:44:30.775 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:45:30.858 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:45:31.353 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:45:31.354 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:45:31.354 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:45:31.396 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:46:31.605 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:46:32.095 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:46:32.095 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:46:32.095 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:46:32.137 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:47:32.324 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:47:32.818 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:47:32.818 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:47:32.819 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:47:32.861 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:48:33.112 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:48:33.610 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:48:33.610 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:48:33.611 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:48:33.652 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:49:30.985 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:49:31.489 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:49:31.490 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:49:31.490 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:49:31.532 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:50:16.398 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:50:16.907 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:50:16.908 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:50:16.908 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:50:16.949 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:50:17.034 19892 WARNING nova.compute.manager [-] Found 7 in the database and 5 on the hypervisor.
2014-06-01 07:50:17.300 19892 INFO nova.compute.manager [-] [instance: 0b2513a1-80a9-4bee-84eb-ba207217a082] During sync_power_state the instance has a pending task. Skip.
2014-06-01 07:50:17.301 19892 INFO nova.compute.manager [-] [instance: bfa190e2-8095-40ea-a4af-bb17e5829815] During sync_power_state the instance has a pending task. Skip.
2014-06-01 07:50:17.301 19892 INFO nova.compute.manager [-] Updating bandwidth usage cache
2014-06-01 07:51:17.520 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:51:18.020 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:51:18.021 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:51:18.021 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:51:18.063 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:52:18.281 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:52:18.774 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 229284
2014-06-01 07:52:18.774 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3650
2014-06-01 07:52:18.775 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 18
2014-06-01 07:52:18.817 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com
2014-06-01 07:53:02.361 19892 AUDIT nova.compute.manager [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Starting instance...
2014-06-01 07:53:02.611 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Attempting claim: memory 4096 MB, disk 20 GB, VCPUs 2
2014-06-01 07:53:02.612 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Total Memory: 258468 MB, used: 29184.00 MB
2014-06-01 07:53:02.612 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Memory limit: 387702.00 MB, free: 358518.00 MB
2014-06-01 07:53:02.612 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Total Disk: 3790 GB, used: 140.00 GB
2014-06-01 07:53:02.613 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Disk limit not specified, defaulting to unlimited
2014-06-01 07:53:02.613 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Total CPU: 32 VCPUs, used: 14.00 VCPUs
2014-06-01 07:53:02.613 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] CPU limit not specified, defaulting to unlimited
2014-06-01 07:53:02.614 19892 AUDIT nova.compute.claims [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Claim successful
2014-06-01 07:53:02.851 19892 INFO nova.openstack.common.rpc.impl_qpid [-] Connected to AMQP server on controller:5672
2014-06-01 07:53:03.144 19892 INFO nova.virt.libvirt.driver [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Creating image
2014-06-01 07:53:04.325 19892 INFO nova.virt.libvirt.driver [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Injecting key into image 8a2fa109-b984-4ca7-9166-ffebfd7b52fc
2014-06-01 07:53:04.772 19892 WARNING nova.virt.disk.vfs.guestfs [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Failed to close augeas aug_close: call launch before using this function\n(in guestfish, don't forget to use the 'run' command)
2014-06-01 07:53:04.777 19892 WARNING nova.virt.disk.api [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] Ignoring error injecting data into image (Error mounting /home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324/disk with libguestfs (guestfs_launch failed.
See http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs
and/or run 'libguestfs-test-tool'.))
2014-06-01 07:53:04.937 19892 INFO nova.virt.libvirt.firewall [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Called setup_basic_filtering in nwfilter
2014-06-01 07:53:04.938 19892 INFO nova.virt.libvirt.firewall [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Ensuring static filters
2014-06-01 07:53:06.465 19892 ERROR nova.virt.libvirt.driver [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] An error occurred while trying to launch a defined domain with xml: <domain type='kvm'>
  <name>instance-000000e8</name>
  <uuid>9478ed82-2a72-4824-b2f6-124a197dc324</uuid>
  <memory unit='KiB'>4194304</memory>
  <currentMemory unit='KiB'>4194304</currentMemory>
  <vcpu placement='static'>2</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat Inc.</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2013.2.3-1.el6</entry>
      <entry name='serial'>e00d6db6-0010-ffff-ffff-ffffff200008</entry>
      <entry name='uuid'>9478ed82-2a72-4824-b2f6-124a197dc324</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='rhel6.5.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='fa:16:3e:71:74:ca'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-000000e8-fa163e7174ca'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2014-06-01 07:53:06.471 19892 ERROR nova.compute.manager [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Instance failed to spawn
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Traceback (most recent call last):
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     block_device_info)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     block_device_info, context=context)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain.XMLDesc(0))
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain.createWithFlags(launch_flags)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     rv = execute(f,*args,**kwargs)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     rv = meth(*args,**kwargs)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] libvirtError: Unable to read from monitor: Connection reset by peer
2014-06-01 07:53:06.471 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] 
2014-06-01 07:53:06.551 19892 AUDIT nova.compute.manager [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Terminating instance
2014-06-01 07:53:06.767 19892 INFO nova.virt.libvirt.driver [-] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Instance destroyed successfully.
2014-06-01 07:53:07.244 19892 INFO nova.virt.libvirt.driver [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Deleting instance files /home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324
2014-06-01 07:53:07.245 19892 INFO nova.virt.libvirt.driver [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Deletion of /home/nova/instances/9478ed82-2a72-4824-b2f6-124a197dc324 complete
2014-06-01 07:53:07.860 19892 ERROR nova.compute.manager [req-9864e00c-97f2-4a65-a064-311b3e569963 2bf9c3b4b60b4423bc70c5a4d8a18b3c 302b6eee9f9d49d18c4ddb9caea4daf5] [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Error: Unable to read from monitor: Connection reset by peer
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] Traceback (most recent call last):
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1043, in _build_instance
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     set_access_ip=set_access_ip)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1426, in _spawn
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     LOG.exception(_('Instance failed to spawn'), instance=instance)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1423, in _spawn
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     block_device_info)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 2087, in spawn
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     block_device_info, context=context)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3245, in _create_domain_and_network
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain = self._create_domain(xml, instance=instance, power_on=power_on)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3188, in _create_domain
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain.XMLDesc(0))
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 3183, in _create_domain
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     domain.createWithFlags(launch_flags)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     rv = execute(f,*args,**kwargs)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     rv = meth(*args,**kwargs)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 708, in createWithFlags
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] libvirtError: Unable to read from monitor: Connection reset by peer
2014-06-01 07:53:07.860 19892 TRACE nova.compute.manager [instance: 9478ed82-2a72-4824-b2f6-124a197dc324] 
2014-06-01 07:53:19.039 19892 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-06-01 07:53:19.558 19892 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 225188
2014-06-01 07:53:19.559 19892 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 3630
2014-06-01 07:53:19.559 19892 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 16
2014-06-01 07:53:19.607 19892 INFO nova.compute.resource_tracker [-] Compute_service record updated for isra010:isra010.il.oracle.com