Hi,
I do not understand why I have this error message.
Is this a configuration or use error, or also a bug? I don't know.
The error is (original code) :
============================
2011-04-24 16:19:31,967 DEBUG nova.rpc [-] Initing the Adapter Consumer for compute from (pid=3107) __init__ /home/openstack/nova/nova/rpc.py:148
2011-04-24 16:20:32,316 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 16:20:32,316 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 16:21:10,578 DEBUG nova.rpc [-] received {u'_context_request_id': u'TMAD3ND8FJBE7W44485V', u'_context_read_deleted': False, u'args': {u'instance_id': 14, u'injected_files': [], u'availability_zone': None}, u'_context_is_admin': True, u'_context_timestamp': u'2011-04-24T14:21:10Z', u'_context_user': u'client1', u'method': u'run_instance', u'_context_project': u'appli1', u'_context_remote_address': None} from (pid=3107) _receive /home/openstack/nova/nova/rpc.py:167
2011-04-24 16:21:10,578 DEBUG nova.rpc [-] unpacked context: {'timestamp': u'2011-04-24T14:21:10Z', 'remote_address': None, 'project': u'appli1', 'is_admin': True, 'user': u'client1', 'request_id': u'TMAD3ND8FJBE7W44485V', 'read_deleted': False} from (pid=3107) _unpack_context /home/openstack/nova/nova/rpc.py:331
2011-04-24 16:21:13,649 AUDIT nova.compute.manager [TMAD3ND8FJBE7W44485V client1 appli1] instance 14: starting...
2011-04-24 16:21:13,773 DEBUG nova.rpc [-] Making asynchronous call on network.6Cloud01 ... from (pid=3107) call /home/openstack/nova/nova/rpc.py:350
2011-04-24 16:21:13,773 DEBUG nova.rpc [-] MSG_ID is 97b27c0938d443998093108cdcee354a from (pid=3107) call /home/openstack/nova/nova/rpc.py:353
2011-04-24 16:21:14,245 DEBUG nova.virt.xenapi.vm_utils [-] Detected KERNEL_RAMDISK format for image 5, instance 14 from (pid=3107) log_disk_format /home/openstack/nova/nova/virt/xenapi/vm_utils.py:494
2011-04-24 16:21:14,488 DEBUG nova.virt.xenapi.vm_utils [-] Size for image 5:4099360 from (pid=3107) _fetch_image_glance_disk /home/openstack/nova/nova/virt/xenapi/vm_utils.py:442
2011-04-24 16:21:15,595 DEBUG nova.virt.xenapi.vm_utils [-] Created VDI OpaqueRef:6d15d8cb-b89d-01b9-efed-56b7bd355807 (Glance image 5, 4099360, False) on OpaqueRef:506f6691-e685-d001-c84d-d9e900c78e36. from (pid=3107) create_vdi /home/openstack/nova/nova/virt/xenapi/vm_utils.py:277
2011-04-24 16:21:15,596 ERROR nova.compute.manager [TMAD3ND8FJBE7W44485V client1 appli1] Instance '14' failed to spawn. Is virtualization enabled in the BIOS?
(nova.compute.manager): TRACE: Traceback (most recent call last):
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/compute/manager.py", line 234, in run_instance
(nova.compute.manager): TRACE: self.driver.spawn(instance_ref)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi_conn.py", line 188, in spawn
(nova.compute.manager): TRACE: self._vmops.spawn(instance)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vmops.py", line 117, in spawn
(nova.compute.manager): TRACE: vdi_uuid = self._create_disk(instance)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vmops.py", line 113, in _create_disk
(nova.compute.manager): TRACE: instance.image_id, user, project, disk_image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 382, in fetch_image
(nova.compute.manager): TRACE: access, image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 537, in _fetch_image_glance
(nova.compute.manager): TRACE: session, instance_id, image, access, image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 452, in _fetch_image_glance_disk
(nova.compute.manager): TRACE: lambda dev:
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 908, in with_vdi_attached_here
(nova.compute.manager): TRACE: this_vm_ref = get_this_vm_ref(session)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 989, in get_this_vm_ref
(nova.compute.manager): TRACE: return session.get_xenapi().VM.get_by_uuid(get_this_vm_uuid())
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 984, in get_this_vm_uuid
(nova.compute.manager): TRACE: with file('/sys/hypervisor/uuid') as f:
(nova.compute.manager): TRACE: IOError: [Errno 2] No such file or directory: '/sys/hypervisor/uuid'
(nova.compute.manager): TRACE:
2011-04-24 16:21:35,374 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 16:21:35,375 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 16:21:38,124 INFO nova.compute.manager [-] Found instance 'instance-0000000e' in DB but no VM. State=8, so setting state to shutoff.
2011-04-24 16:21:38,124 INFO nova.compute.manager [-] DB/VM state mismatch. Changing state from '8' to '5'
2011-04-24 16:22:38,462 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 16:22:38,462 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 16:22:41,209 INFO nova.compute.manager [-] Found instance 'instance-0000000e' in DB but no VM. State=5, so setting state to shutoff.
An other error with modified code :
=================================
(change code in file "vm_utils.py" and remplace this line "with file('/sys/hypervisor/uuid') as f:" by
"with file('/tsys/hypervisor/uuid') as f:" after created local directory "/tsys" and recopied uuid from xensever in local)
2011-04-24 23:22:21,561 AUDIT nova.compute.manager [YLNPS1L-9EK9TP181TI3 client1 appli1] instance 15: starting...
2011-04-24 23:22:21,659 DEBUG nova.rpc [-] Making asynchronous call on network.6Cloud01 ... from (pid=2295) call /home/openstack/nova/nova/rpc.py:350
2011-04-24 23:22:21,660 DEBUG nova.rpc [-] MSG_ID is 5ca2b06a8d41496d97cdee61d93590ad from (pid=2295) call /home/openstack/nova/nova/rpc.py:353
2011-04-24 23:22:22,075 DEBUG nova.virt.xenapi.vm_utils [-] Detected KERNEL_RAMDISK format for image 5, instance 15 from (pid=2295) log_disk_format /home/openstack/nova/nova/virt/xenapi/vm_utils.py:494
2011-04-24 23:22:22,359 DEBUG nova.virt.xenapi.vm_utils [-] Size for image 5:4099360 from (pid=2295) _fetch_image_glance_disk /home/openstack/nova/nova/virt/xenapi/vm_utils.py:442
2011-04-24 23:22:23,514 DEBUG nova.virt.xenapi.vm_utils [-] Created VDI OpaqueRef:a657cbd0-9b53-781c-0fc3-a39d55660b35 (Glance image 5, 4099360, False) on OpaqueRef:506f6691-e685-d001-c84d-d9e900c78e36. from (pid=2295) create_vdi /home/openstack/nova/nova/virt/xenapi/vm_utils.py:277
2011-04-24 23:22:23,565 DEBUG nova.virt.xenapi.vm_utils [-] Creating VBD for VDI OpaqueRef:a657cbd0-9b53-781c-0fc3-a39d55660b35 ... from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:922
2011-04-24 23:22:23,623 DEBUG nova.virt.xenapi.vm_utils [-] Creating VBD for VDI OpaqueRef:a657cbd0-9b53-781c-0fc3-a39d55660b35 done. from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:924
2011-04-24 23:22:23,623 DEBUG nova.virt.xenapi.vm_utils [-] Plugging VBD OpaqueRef:02352066-27e6-7c1b-f034-c13172b5fe61 ... from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:926
2011-04-24 23:22:25,569 DEBUG nova.virt.xenapi.vm_utils [-] Plugging VBD OpaqueRef:02352066-27e6-7c1b-f034-c13172b5fe61 done. from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:928
2011-04-24 23:22:25,624 DEBUG nova.virt.xenapi.vm_utils [-] VBD OpaqueRef:02352066-27e6-7c1b-f034-c13172b5fe61 plugged as xvda from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:930
2011-04-24 23:22:26,573 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 23:22:26,573 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 23:22:29,278 INFO nova.compute.manager [-] Found instance 'instance-0000000f' in DB but no VM. State=0, so assuming spawn is in progress.
2011-04-24 23:22:35,646 DEBUG nova.virt.xenapi.vm_utils [-] Destroying VBD for VDI OpaqueRef:a657cbd0-9b53-781c-0fc3-a39d55660b35 ... from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:942
2011-04-24 23:22:37,510 DEBUG nova.virt.xenapi.vm_utils [-] VBD.unplug successful first time. from (pid=2295) vbd_unplug_with_retry /home/openstack/nova/nova/virt/xenapi/vm_utils.py:957
2011-04-24 23:22:37,556 DEBUG nova.virt.xenapi.vm_utils [-] Destroying VBD for VDI OpaqueRef:a657cbd0-9b53-781c-0fc3-a39d55660b35 done. from (pid=2295) with_vdi_attached_here /home/openstack/nova/nova/virt/xenapi/vm_utils.py:945
2011-04-24 23:22:37,556 ERROR nova.compute.manager [YLNPS1L-9EK9TP181TI3 client1 appli1] Instance '15' failed to spawn. Is virtualization enabled in the BIOS?
(nova.compute.manager): TRACE: Traceback (most recent call last):
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/compute/manager.py", line 234, in run_instance
(nova.compute.manager): TRACE: self.driver.spawn(instance_ref)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi_conn.py", line 188, in spawn
(nova.compute.manager): TRACE: self._vmops.spawn(instance)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vmops.py", line 117, in spawn
(nova.compute.manager): TRACE: vdi_uuid = self._create_disk(instance)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vmops.py", line 113, in _create_disk
(nova.compute.manager): TRACE: instance.image_id, user, project, disk_image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 382, in fetch_image
(nova.compute.manager): TRACE: access, image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 537, in _fetch_image_glance
(nova.compute.manager): TRACE: session, instance_id, image, access, image_type)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 452, in _fetch_image_glance_disk
(nova.compute.manager): TRACE: lambda dev:
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 939, in with_vdi_attached_here
(nova.compute.manager): TRACE: _wait_for_device(dev)
(nova.compute.manager): TRACE: File "/home/openstack/nova/nova/virt/xenapi/vm_utils.py", line 904, in _wait_for_device
(nova.compute.manager): TRACE: raise StorageError(_('Timeout waiting for device %s to be created') % dev)
(nova.compute.manager): TRACE: StorageError: Timeout waiting for device xvda to be created
(nova.compute.manager): TRACE:
2011-04-24 23:23:29,558 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 23:23:29,558 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 23:23:32,049 INFO nova.compute.manager [-] Found instance 'instance-0000000f' in DB but no VM. State=8, so setting state to shutoff.
2011-04-24 23:23:32,050 INFO nova.compute.manager [-] DB/VM state mismatch. Changing state from '8' to '5'
2011-04-24 23:24:32,372 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
2011-04-24 23:24:32,373 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenapi power_state -> |1|
2011-04-24 23:24:34,892 INFO nova.compute.manager [-] Found instance 'instance-0000000f' in DB but no VM. State=5, so setting state to shutoff.
2011-04-24 23:25:35,177 INFO nova.virt.xenapi.vm_utils [-] (VM_UTILS) xenserver vm state -> |Running|
We can see more details (https://answers.launchpad.net/nova/+question/153853) and also a extract (see below) of local storage via XenCenter
Thank you for your help.
Regards,
[root@xenserver-01 ~]# xe vdi-list <CR> # extract
uuid ( RO) : 08e969f9-4178-46d1-b02a-a9341c9bc87d
name-label ( RW): Glance image 2
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : c821a620-da0b-4f39-a4a2-5f2ff7f085e2
name-label ( RW): Glance image 2
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 8bb394a5-a959-4d7e-8518-dcb00f596074
name-label ( RW): Glance image 4
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 8388608
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : fa05d438-117b-4f92-a1a4-a3c9908a067a
name-label ( RW): Glance image 2
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 71cbf264-c022-408b-9030-040870738885
name-label ( RW): Glance image 1
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 6291456
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 86178586-f3dc-424c-aefe-2725d3d4b4af
name-label ( RW): Glance image 5
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 1f1e9c9f-7d2c-466c-99bb-314e1dc1e5bb
name-label ( RW): Glance image 2
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 08ef59b9-8061-4cd3-91d7-d952bb8e3f29
name-label ( RW): 0
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 6442450944
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 17dd4ae9-7c9e-4225-85eb-d0192c1ece80
name-label ( RW): Glance image 5
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 24c6fd90-57eb-47c3-b290-d1bab2dc89ee
name-label ( RW): Glance image 5
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
uuid ( RO) : 32c6a12e-4d87-4ad4-951e-3b1f1a557be9
name-label ( RW): Glance image 5
name-description ( RW):
sr-uuid ( RO): 7ed9b60c-367f-6c25-3ef7-dd492acd8996
virtual-size ( RO): 4194304
sharable ( RO): false
read-only ( RO): false
Hi Laurent,
I think this may be a configuration issue. The current nova xenapi code requires that nova-compute be run inside a VM on the actual XenServer host machine it is controlling. If you do this then you should automatically have the /sys/hypervisor /uuid file available for nova-compute to read.
The nova xenapi plugins (which get installed on the XenServer itself) use this to create and mount a VDI device in the nova-compute VM where the raw image data can be written.
Hope this helps.
Dan