Comment 12 for bug 1353939

Revision history for this message
Matt Riedemann (mriedem) wrote :

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