Open Stack

Hi all,
I have a problem to consult, this problem occurs in _create_image when I boot a new instance(someone else may boot one at the same time).
The instance UUID of mine is e8752971-d390-450f-a083-819b7716fd53, and it booted failed, the other instance UUID is 79e7b88f-2302-4387-a27e-ffdbd483f6d2, it booted successfully.
the problem occurs when these two instances convert the same base image from qcow2 to raw(in the fetch_to_raw method) at the same time, the convert cmd of my instance is failed with error: 'qemu-img: error while writing sector 634880: Input/output error', the convertion starting time of my instance is 2012-09-21 17:54:58, one second ahead of the other instance 2012-09-21 17:54:59.
So I think this is a concurrency issue, what about guys think about it?
the log message is listed below:
1. receive 'run_instance' message from AMQP:
2012-09-21 17:48:42 DEBUG nova.rpc.amqp [-] received {u'_context_roles': [u'', u'admin'], u'_context_request_id': u'req-65ffd7d5-f615-4ee0-8007-f71657227632', u'_context_read_deleted': u'no', u'args': {u'instance_uuid': u'e8752971-d390-450f-a083-819b7716fd53', u'requested_networks': None, u'availability_zone': u'nova12', u'admin_password': '<SANITIZED>', u'injected_files': [[u'/etc/vm_monitor/info', u'{"service":"RDS","ori_user":"cc130e62151540c09e1745841e8b3ff6","resource_type":"RDS","resource_id":"889","aggregation_item_name":"","aggregation_item_value":""}']], u'is_first_time': True}, u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'_context_project_id': u'844dc9fb4ad9499ea97b07c7b6cee137', u'_context_timestamp': u'2012-09-21T09:48:42.304584', u'_context_user_id': u'64d4d53b99f84cf1ba6becd72ed10982', u'method': u'run_instance', u'_context_remote_address': u'10.120.40.28'} from (pid=28544) _safe_log /usr/lib/python2.7/dist-packages/nova/rpc/common.py:160
2012-09-21 17:48:43 DEBUG nova.rpc.amqp [-] received {u'_context_roles': [u'', u'admin'], u'_context_request_id': u'req-4202dc5f-022f-4c1b-bfbf-71dae31f5476', u'_context_read_deleted': u'no', u'args': {u'instance_uuid': u'79e7b88f-2302-4387-a27e-ffdbd483f6d2', u'requested_networks': None, u'availability_zone': u'nova12', u'admin_password': '<SANITIZED>', u'injected_files': [[u'/etc/vm_monitor/info', u'{"service":"RDS","ori_user":"cc130e62151540c09e1745841e8b3ff6","resource_type":"RDS","resource_id":"890","aggregation_item_name":"","aggregation_item_value":""}']], u'is_first_time': True}, u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'_context_project_id': u'844dc9fb4ad9499ea97b07c7b6cee137', u'_context_timestamp': u'2012-09-21T09:48:43.024286', u'_context_user_id': u'64d4d53b99f84cf1ba6becd72ed10982', u'method': u'run_instance', u'_context_remote_address': u'10.120.40.28'} from (pid=28544) _safe_log /usr/lib/python2.7/dist-packages/nova/rpc/common.py:160
2. create image:
2012-09-21 17:48:48 INFO nova.virt.libvirt.connection [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] [instance: e8752971-d390-450f-a083-819b7716fd53] Creating image
2012-09-21 17:54:51 DEBUG nova.utils [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Running cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-09-21 17:54:51 DEBUG nova.utils [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Running cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-09-21 17:54:58 DEBUG nova.virt.images [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] 2fd9c9e7-115d-4a39-8ea3-3adc9f0dda68 was qcow2, converting to raw from (pid=28544) fetch_to_raw /usr/lib/python2.7/dist-packages/nova/virt/images.py:104
2012-09-21 17:54:58 DEBUG nova.utils [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Running cmd (subprocess): qemu-img convert -O raw /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.converted from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-09-21 17:54:59 DEBUG nova.utils [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Result was 1 from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:235
2012-09-21 17:54:59 ERROR nova.compute.manager [req-65ffd7d5-f615-4ee0-8007-f71657227632 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] [instance: e8752971-d390-450f-a083-819b7716fd53] Instance failed to spawn
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] Traceback (most recent call last):
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 606, in _spawn
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     self._legacy_nw_info(network_info), block_device_info)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     return f(*args, **kw)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 1018, in spawn
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     block_device_info=block_device_info)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 1439, in _create_image
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     basepath('disk'), size)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/utils.py", line 296, in fetch_image
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     images.fetch_to_raw(context, image_id, target, user_id, project_id)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/virt/images.py", line 106, in fetch_to_raw
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     path_tmp, staged)
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]   File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 242, in execute
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53]     cmd=' '.join(cmd))
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] ProcessExecutionError: Unexpected error while running command.
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] Command: qemu-img convert -O raw /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.converted
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] Exit code: 1
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] Stdout: ''
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] Stderr: 'qemu-img: error while writing sector 634880: Input/output error\n'  ###ERROR
2012-09-21 17:54:59 TRACE nova.compute.manager [instance: e8752971-d390-450f-a083-819b7716fd53] 

2012-09-21 17:48:49 INFO nova.virt.libvirt.connection [req-4202dc5f-022f-4c1b-bfbf-71dae31f5476 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] [instance: 79e7b88f-2302-4387-a27e-ffdbd483f6d2] Creating image
2012-09-21 17:54:59 DEBUG nova.utils [req-4202dc5f-022f-4c1b-bfbf-71dae31f5476 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Running cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-09-21 17:54:59 DEBUG nova.virt.images [req-4202dc5f-022f-4c1b-bfbf-71dae31f5476 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] 2fd9c9e7-115d-4a39-8ea3-3adc9f0dda68 was qcow2, converting to raw from (pid=28544) fetch_to_raw /usr/lib/python2.7/dist-packages/nova/virt/images.py:104
2012-09-21 17:54:59 DEBUG nova.utils [req-4202dc5f-022f-4c1b-bfbf-71dae31f5476 64d4d53b99f84cf1ba6becd72ed10982 844dc9fb4ad9499ea97b07c7b6cee137] Running cmd (subprocess): qemu-img convert -O raw /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.part /data/openstack/nova/instances/_base/3554d26efea057ec9dd8029a0a3ceddc0359b70d.converted from (pid=28544) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-09-21 17:57:50 INFO nova.virt.libvirt.connection [-] [instance: 79e7b88f-2302-4387-a27e-ffdbd483f6d2] Instance spawned successfully.    ###OK