xenapi create_vdi error

Asked by Laurent Borensky

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

Question information

Language:
English Edit question
Status:
Answered
For:
OpenStack Compute (nova) Edit question
Assignee:
No assignee Edit question
Last query:
Last reply:

This question was originally filed as bug #770141.

Revision history for this message
Thierry Carrez (ttx) said :
#1

I'll assume it does solve your issue -- If not please reopen the bug by setting its status back to New.

Revision history for this message
Thierry Carrez (ttx) said :
#2

From DanPrince:

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

Can you help with this problem?

Provide an answer of your own, or ask Laurent Borensky for more information if necessary.

To post a message you must log in.