2014-01-16 18:48:24 |
Adam Gandelman |
description |
In some cases (not for all instances, just for some) the following error prevents creating the snapshot:
2013-10-25 14:49:30.724 22980 AUDIT nova.compute.manager [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] instance snapshotting
2013-10-25 14:49:30.944 22980 INFO nova.virt.libvirt.driver [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] Beginning live snapshot process
2013-10-25 14:49:32.006 22980 INFO nova.virt.libvirt.driver [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] Snapshot extracted, beginning image upload
2013-10-25 14:49:32.329 22980 ERROR nova.openstack.common.rpc.amqp [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] Exception during message handling
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 461, in _process_data
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp **args)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp result = getattr(proxyobj, method)(ctxt, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 353, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 90, in wrapped
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp payload)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 73, in wrapped
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return f(self, context, *args, **kw)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 243, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp pass
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 229, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 271, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp e, sys.exc_info())
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 258, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 319, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp % image_id, instance=instance)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 309, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2293, in snapshot_instance
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp task_states.IMAGE_SNAPSHOT)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2324, in _snapshot_instance
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp update_task_state)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 1397, in snapshot
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp image_format)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 1483, in _live_snapshot
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp libvirt.VIR_DOMAIN_BLOCK_REBASE_SHALLOW)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 179, in doit
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp result = proxy_call(self._autowrap, f, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 139, in proxy_call
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp rv = execute(f,*args,**kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 77, in tworker
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp rv = meth(*args,**kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/libvirt.py", line 646, in blockRebase
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp if ret == -1: raise libvirtError ('virDomainBlockRebase() failed', dom=self)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp libvirtError: internal error: unable to execute QEMU command 'drive-mirror': Could not open '/var/lib/nova/instances/snapshots/tmp5DdrIO/236df3e170e64fabaeb3c7601e2d6c47.delta'
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp
The directory /var/lib/nova/instances/snapshots/tmp5DdrIO does not exist immidiately after this error shows up.
Permissions to the parent directory are nova:nova 755, I believe they are correct.
Package: nova-compute
Version: 1:2013.2-0ubuntu1~cloud0 |
---- SRU Justification ---
[Impact]
In a libvirt-based OpenStack deployment, Nova fails to snapshot instances, failing with error:
internal error: unable to execute QEMU command 'drive-mirror': Could not open '/var/lib/nova/instances/snapshots/tmp5DdrIO/236df3e170e64fabaeb3c7601e2d6c47.delta'
I had originally discovered this bug using the Tempset test suite while verifying an unrelated OpenStack SRU, but other users are experiencing this in the wild.
[Test Case]
Deploy an OpenStack cloud based on Ubuntu Saucy and OpenStack Havana, then attempt to snapshot a running instance. The Tempest integration test suite contains a snapshot test case: tempest.api.compute.images.test_images_oneserver.ImagesOneServerTestJSON.test_create_delete_image [1]
[Regression Potential]
The proposed fix is isolated to the libvirt packaging and simply appends an additional directory exception to the packages apparmor configuration, so that libvirt has appropriate access to the directory used during the process of snapshotting an instance.
[1]https://github.com/openstack/tempest/blob/master/tempest/api/compute/images/test_images_oneserver.py#L92
--- Original Bug ---
In some cases (not for all instances, just for some) the following error prevents creating the snapshot:
2013-10-25 14:49:30.724 22980 AUDIT nova.compute.manager [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] instance snapshotting
2013-10-25 14:49:30.944 22980 INFO nova.virt.libvirt.driver [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] Beginning live snapshot process
2013-10-25 14:49:32.006 22980 INFO nova.virt.libvirt.driver [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] [instance: db9c8a72-6ce2-41b7-8f7a-be0be8468667] Snapshot extracted, beginning image upload
2013-10-25 14:49:32.329 22980 ERROR nova.openstack.common.rpc.amqp [req-6e9326d7-64df-40f7-bc81-190ec5234de2 657f1aca48d24eaf9655e0b77b2bc6d9 35b2b08cc3f44a538cf3535043793a2a] Exception during message handling
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 461, in _process_data
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp **args)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp result = getattr(proxyobj, method)(ctxt, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 353, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 90, in wrapped
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp payload)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 73, in wrapped
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return f(self, context, *args, **kw)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 243, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp pass
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 229, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 271, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp e, sys.exc_info())
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 258, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 319, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp % image_id, instance=instance)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 309, in decorated_function
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2293, in snapshot_instance
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp task_states.IMAGE_SNAPSHOT)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2324, in _snapshot_instance
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp update_task_state)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 1397, in snapshot
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp image_format)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 1483, in _live_snapshot
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp libvirt.VIR_DOMAIN_BLOCK_REBASE_SHALLOW)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 179, in doit
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp result = proxy_call(self._autowrap, f, *args, **kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 139, in proxy_call
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp rv = execute(f,*args,**kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 77, in tworker
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp rv = meth(*args,**kwargs)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/libvirt.py", line 646, in blockRebase
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp if ret == -1: raise libvirtError ('virDomainBlockRebase() failed', dom=self)
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp libvirtError: internal error: unable to execute QEMU command 'drive-mirror': Could not open '/var/lib/nova/instances/snapshots/tmp5DdrIO/236df3e170e64fabaeb3c7601e2d6c47.delta'
2013-10-25 14:49:32.329 22980 TRACE nova.openstack.common.rpc.amqp
The directory /var/lib/nova/instances/snapshots/tmp5DdrIO does not exist immidiately after this error shows up.
Permissions to the parent directory are nova:nova 755, I believe they are correct.
Package: nova-compute
Version: 1:2013.2-0ubuntu1~cloud0 |
|