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
_______________________________________________
Mailing list: https://launchpad.net/~openstack
Post to : openstack@lists.launchpad.net
Unsubscribe : https://launchpad.net/~openstack
More help : https://help.launchpad.net/ListHelp
