I see this on instance create sometimes in our internal CI running in nested virt (qemu) on RHEL 7.1.
This is the error from the nova compute logs:
2015-05-09 17:09:35.298 4449 ERROR nova.compute.manager [req-f3ae72f5-6139-4031-b527-e506e321f4ab - - - - -] [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] Instance failed to spawn 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] Traceback (most recent call last): 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2501, in _build_resources 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] yield resources 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2365, in _build_and_run_instance 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] block_device_info=block_device_info) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2354, in spawn 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] block_device_info=block_device_info) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4391, in _create_domain_and_network 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] power_on=power_on) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4322, in _create_domain 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] LOG.error(err) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__ 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] six.reraise(self.type_, self.value, self.tb) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4312, in _create_domain 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] domain.createWithFlags(launch_flags) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] result = proxy_call(self._autowrap, f, *args, **kwargs) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] rv = execute(f, *args, **kwargs) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] six.reraise(c, e, tb) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] rv = meth(*args, **kwargs) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] File "/usr/lib64/python2.7/site-packages/libvirt.py", line 996, in createWithFlags 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self) 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] libvirtError: internal error: Process exited prior to exec: libvirt: error : Failed to terminate process 7231 with SIGKILL: Device or resource busy 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def] 2015-05-09 17:09:35.298 4449 TRACE nova.compute.manager [instance: 6e8122a8-0a18-408c-8518-5ed2f7470def]
This is the error from the qemu log for the instance/domain xml:
2015-05-09 22:09:20.235+0000: starting up LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=none /usr/bin/qemu-system-x86_64 -name instance-00000002 -S -machine pc-i440fx-rhel7.0.0,accel=tcg,usb=off -m 512 -realtime mlock=off -smp 1,sockets=1,cores=1,threads=1 -uuid 6e8122a8-0a18-408c-8518-5ed2f7470def -smbios type=1,manufacturer=IBM,product=OpenStack Nova,version=2015.1-201505071728.ibm.el7.119,serial=a66bfaaf-bb7a-7736-c706-5e51fb70bdb3,uuid=6e8122a8-0a18-408c-8518-5ed2f7470def -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/instance-00000002.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -kernel /var/lib/nova/instances/6e8122a8-0a18-408c-8518-5ed2f7470def/kernel -initrd /var/lib/nova/instances/6e8122a8-0a18-408c-8518-5ed2f7470def/ramdisk -append root=/dev/vda console=tty0 console=ttyS0 no_timer_check -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/var/lib/nova/instances/6e8122a8-0a18-408c-8518-5ed2f7470def/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=23,id=hostnet0 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=fa:16:3e:d3:88:ad,bus=pci.0,addr=0x3 -chardev file,id=charserial0,path=/var/lib/nova/instances/6e8122a8-0a18-408c-8518-5ed2f7470def/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 127.0.0.1:0 -k en-us -vga cirrus -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 -msg timestamp=on libvirt: error : Failed to terminate process 7231 with SIGKILL: Device or resource busy 2015-05-09 22:09:35.293+0000: shutting down
I see this on instance create sometimes in our internal CI running in nested virt (qemu) on RHEL 7.1.
This is the error from the nova compute logs:
2015-05-09 17:09:35.298 4449 ERROR nova.compute. manager [req-f3ae72f5- 6139-4031- b527-e506e321f4 ab - - - - -] [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] Instance failed to spawn manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] Traceback (most recent call last): manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/compute/ manager. py", line 2501, in _build_resources manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] yield resources manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/compute/ manager. py", line 2365, in _build_ and_run_ instance manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] block_device_ info=block_ device_ info) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/virt/ libvirt/ driver. py", line 2354, in spawn manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] block_device_ info=block_ device_ info) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/virt/ libvirt/ driver. py", line 4391, in _create_ domain_ and_network manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] power_on=power_on) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/virt/ libvirt/ driver. py", line 4322, in _create_domain manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] LOG.error(err) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ oslo_utils/ excutils. py", line 85, in __exit__ manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] six.reraise( self.type_ , self.value, self.tb) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ nova/virt/ libvirt/ driver. py", line 4312, in _create_domain manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] domain. createWithFlags (launch_ flags) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ eventlet/ tpool.py" , line 183, in doit manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] result = proxy_call( self._autowrap, f, *args, **kwargs) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ eventlet/ tpool.py" , line 141, in proxy_call manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] rv = execute(f, *args, **kwargs) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ eventlet/ tpool.py" , line 122, in execute manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] six.reraise(c, e, tb) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib/ python2. 7/site- packages/ eventlet/ tpool.py" , line 80, in tworker manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] rv = meth(*args, **kwargs) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] File "/usr/lib64/ python2. 7/site- packages/ libvirt. py", line 996, in createWithFlags manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] if ret == -1: raise libvirtError ('virDomainCrea teWithFlags( ) failed', dom=self) manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] libvirtError: internal error: Process exited prior to exec: libvirt: error : Failed to terminate process 7231 with SIGKILL: Device or resource busy manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef] manager [instance: 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef]
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
2015-05-09 17:09:35.298 4449 TRACE nova.compute.
This is the error from the qemu log for the instance/domain xml:
2015-05-09 22:09:20.235+0000: starting up local/sbin: /usr/local/ bin:/usr/ sbin:/usr/ bin QEMU_AUDIO_DRV=none /usr/bin/ qemu-system- x86_64 -name instance-00000002 -S -machine pc-i440fx- rhel7.0. 0,accel= tcg,usb= off -m 512 -realtime mlock=off -smp 1,sockets= 1,cores= 1,threads= 1 -uuid 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef -smbios type=1, manufacturer= IBM,product= OpenStack Nova,version= 2015.1- 201505071728. ibm.el7. 119,serial= a66bfaaf- bb7a-7736- c706-5e51fb70bd b3,uuid= 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef -no-user-config -nodefaults -chardev socket, id=charmonitor, path=/var/ lib/libvirt/ qemu/instance- 00000002. monitor, server, nowait -mon chardev= charmonitor, id=monitor, mode=control -rtc base=utc -no-shutdown -boot strict=on -kernel /var/lib/ nova/instances/ 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef/kernel -initrd /var/lib/ nova/instances/ 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef/ramdisk -append root=/dev/vda console=tty0 console=ttyS0 no_timer_check -device piix3-usb- uhci,id= usb,bus= pci.0,addr= 0x1.0x2 -drive file=/var/ lib/nova/ instances/ 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef/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= 23,id=hostnet0 -device virtio- net-pci, netdev= hostnet0, id=net0, mac=fa: 16:3e:d3: 88:ad,bus= pci.0,addr= 0x3 -chardev file,id= charserial0, path=/var/ lib/nova/ instances/ 6e8122a8- 0a18-408c- 8518-5ed2f7470d ef/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 127.0.0.1:0 -k en-us -vga cirrus -device virtio- balloon- pci,id= balloon0, bus=pci. 0,addr= 0x5 -msg timestamp=on
LC_ALL=C PATH=/usr/
libvirt: error : Failed to terminate process 7231 with SIGKILL: Device or resource busy
2015-05-09 22:09:35.293+0000: shutting down