Bug 1033714 - cinder: can't delete snapshot after 'GlusterfsException: Timed out while waiting for Nova update for creation of snapshot' Edit
Summary: cinder: can't delete snapshot after 'GlusterfsException: Timed out while wait...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-cinder
Version: 4.0
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: z1
: 4.0
Assignee: Eric Harney
QA Contact: Yogev Rabl
URL:
Whiteboard: storage
Depends On: 1016798 1033652 1040711
Blocks: 1045196
TreeView+ depends on / blocked
 
Reported: 2013-11-22 16:59 UTC by Dafna Ron
Modified: 2016-04-26 18:14 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
This is a tracker bug. Its child bugs introduce several fixes for deletion of snapshots attached to GlusterFS Cinder volumes.
Clone Of:
Environment:
Last Closed: 2014-01-23 14:22:38 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
logs (18.59 MB, application/x-gzip)
2013-11-22 16:59 UTC, Dafna Ron
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Launchpad 1254100 0 None None None Never
Red Hat Product Errata RHBA-2014:0046 0 normal SHIPPED_LIVE Red Hat Enterprise Linux OpenStack Platform 4 Bug Fix and Enhancement Advisory 2014-01-23 00:51:59 UTC

Description Dafna Ron 2013-11-22 16:59:41 UTC
Created attachment 827894 [details]
logs

Description of problem:

I terminated an instance in horizon while at the same time ran snapshot-create in the cli.
after a time out error we cannot delete the snapshot.

Version-Release number of selected component (if applicable):

openstack-cinder-2013.2-2.el6ost.noarch

How reproducible:

100%

Steps to Reproduce:
1. create a volume 
2. boot an image from the volume 
3. do the following at the same time: 
* run from cli:  cinder snapshot-create <volume> --display-name <name> --force=True
* From Horizon: destroy the instance 
4. after status changes to error try to delete the snapshot

Actual results:

after a few minutes we would get a timeout and the snapshot will change to status error. 
if we try to delete it we get a keyerror and we cannot delete the snapshot 

Expected results:

we should be able to delete the snapshot 

Additional info:


2013-11-22 18:29:12.991 14458 ERROR cinder.openstack.common.rpc.amqp [req-684511db-14f3-441f-8262-86cdef07fa8d 24b77982be8049ee9cd5ad7bed913565 7eb59aa89e8944d098554ff6f5a4cf88] Exception during message handling
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp **args)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 808, in wrapper
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 371, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp {'status': 'error'})
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp self.gen.next()
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 362, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp model_update = self.driver.create_snapshot(snapshot_ref)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 431, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp raise exception.GlusterfsException(msg)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: Timed out while waiting for Nova update for creation of snapshot 58aa33b7-50ad-4cd2-9f62-7efc84bbc7c6.
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp
(END)

trying to remove the snapshot we will get:

2013-11-22 18:29:12.991 14458 ERROR cinder.openstack.common.rpc.amqp [req-684511db-14f3-441f-8262-86cdef07fa8d 24b77982be8049ee9cd5ad7bed913565 7eb59aa89e8944d098554ff6f5a4cf88] Exception during message handling
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp **args)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 808, in wrapper
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 371, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp {'status': 'error'})
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp self.gen.next()
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 362, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp model_update = self.driver.create_snapshot(snapshot_ref)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 431, in create_snapshot
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp raise exception.GlusterfsException(msg)
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: Timed out while waiting for Nova update for creation of snapshot 58aa33b7-50ad-4cd2-9f62-7efc84bbc7c6.
2013-11-22 18:29:12.991 14458 TRACE cinder.openstack.common.rpc.amqp
2013-11-22 18:34:15.662 14458 ERROR cinder.openstack.common.rpc.amqp [req-2d371aff-084d-4200-b8aa-57f0ddb7e831 24b77982be8049ee9cd5ad7bed913565 7eb59aa89e8944d098554ff6f5a4cf88] Exception during message handling
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp **args)
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 808, in wrapper
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 424, in delete_snapshot
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp {'status': 'error_deleting'})
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp self.gen.next()
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 412, in delete_snapshot
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp self.driver.delete_snapshot(snapshot_ref)
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 550, in delete_snapshot
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp snapshot_file = snap_info[snapshot['id']]
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp KeyError: u'58aa33b7-50ad-4cd2-9f62-7efc84bbc7c6'
2013-11-22 18:34:15.662 14458 TRACE cinder.openstack.common.rpc.amqp

Comment 1 Ayal Baron 2013-11-27 07:16:01 UTC
Eric, this looks like yet another case of task flow?

Comment 2 Eric Harney 2013-11-27 13:45:40 UTC
Not completely -- if she got a KeyError then this is likely another symptom of bug 1016798 / bug 1016806 and associated changes.

Comment 3 Ayal Baron 2013-12-01 09:49:22 UTC
(In reply to Eric Harney from comment #2)
> Not completely -- if she got a KeyError then this is likely another symptom
> of bug 1016798 / bug 1016806 and associated changes.

So either block it on these bugs or mark as dup?

Comment 4 Dafna Ron 2013-12-12 11:53:29 UTC
we are failing to delete the snapshot with :

[root@cougar06 ~(keystone_admin)]# cinder snapshot-list 
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
|                  ID                  |              Volume ID               |     Status     |        Display Name        | Size |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
| 1264bdc0-fc0a-4817-976c-ce061a787d92 | 8e113c6f-f30c-4f6a-b511-2af507d7e758 | error_deleting |           test7            |  6   |
| 203b01c2-ac31-420f-a5e1-f12228c63ad1 | eafb3095-5b12-4ebb-97d9-212e95762323 | error_deleting |        after-attch         |  9   |
| 31969c75-70fa-4719-be49-4af05e0df97b | b4c7df4e-0508-4e4f-86ff-6baee6975123 |     error      |           test5            |  7   |
| 6b0eab08-fd8a-434d-a7f9-9aca502ee192 | 80ea6146-9155-4b0e-8580-790d862e390e |    creating    |       vol9_snapshot        |  40  |
| 7fedd82b-c2f0-45e7-a200-1e02d3342fa7 | a6c603c1-7ea6-4341-a514-a99ad5215668 |     error      |        from_image2         |  15  |
| 8a07e46d-7f36-443c-a36e-9e26e811cb32 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |   snapshot for vol_snap3   |  10  |
| e451bc81-b96c-495f-a64b-477489bc2d9f | 609d201e-f34a-4f7f-953c-3c1b5c087873 |     error      | create_from_vol_after_boot |  8   |
| f443126d-1408-4ce0-bfe7-d385b6fab797 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |          only_vol          |  10  |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
[root@cougar06 ~(keystone_admin)]# tail -f /var/log/cinder/volume.log 
2013-12-12 13:09:54.448 3860 TRACE cinder.openstack.common.rpc.amqp Stderr: "Could not open '/var/lib/cinder/mnt/249458a2755cd0a9f302b9d81eb3f35d/volume-a6c603c1-7ea6-4341-a514-a99ad5215668.e6a17a21-f59b-4a59-a38e-bd934723bea3': No such file or directory\n"
2013-12-12 13:09:54.448 3860 TRACE cinder.openstack.common.rpc.amqp 
2013-12-12 13:22:39.539 3860 WARNING cinder.quota [req-0b81b279-15c0-4744-abe0-9fd45c876264 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: gigabytes is set by the default quota flag: quota_gigabytes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:22:39.540 3860 WARNING cinder.quota [req-0b81b279-15c0-4744-abe0-9fd45c876264 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: volumes is set by the default quota flag: quota_volumes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:23:06.755 3860 WARNING cinder.quota [req-19d4754d-f270-4f46-8d72-fa9377e55dd5 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: gigabytes is set by the default quota flag: quota_gigabytes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:23:06.756 3860 WARNING cinder.quota [req-19d4754d-f270-4f46-8d72-fa9377e55dd5 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: volumes is set by the default quota flag: quota_volumes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:28:37.182 3860 WARNING cinder.quota [req-12540d80-a53e-49e5-91c8-30066b815542 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: gigabytes is set by the default quota flag: quota_gigabytes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:28:37.182 3860 WARNING cinder.quota [req-12540d80-a53e-49e5-91c8-30066b815542 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: snapshots is set by the default quota flag: quota_snapshots, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:29:41.894 3860 WARNING cinder.quota [req-0862cd5c-c642-4336-8b05-f7fb1890ad72 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: gigabytes is set by the default quota flag: quota_gigabytes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:29:41.895 3860 WARNING cinder.quota [req-0862cd5c-c642-4336-8b05-f7fb1890ad72 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: volumes is set by the default quota flag: quota_volumes, it is now deprecated. Please use the the default quota class for default quota.





2013-12-12 13:41:15.353 3860 ERROR cinder.openstack.common.rpc.amqp [req-ace304ca-024e-4f0c-a1bf-1f13fca4ef7c 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Exception during message handling
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     **args)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 809, in wrapper
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     return func(self, *args, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 371, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     {'status': 'error'})
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 362, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     model_update = self.driver.create_snapshot(snapshot_ref)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 445, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     raise exception.GlusterfsException(msg)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: Timed out while waiting for Nova update for creation of snapshot 6b0eab08-fd8a-434d-a7f9-9aca502ee192.
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp 
^C
[root@cougar06 ~(keystone_admin)]# 
[root@cougar06 ~(keystone_admin)]# cinder snapshot-list 
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
|                  ID                  |              Volume ID               |     Status     |        Display Name        | Size |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
| 1264bdc0-fc0a-4817-976c-ce061a787d92 | 8e113c6f-f30c-4f6a-b511-2af507d7e758 | error_deleting |           test7            |  6   |
| 203b01c2-ac31-420f-a5e1-f12228c63ad1 | eafb3095-5b12-4ebb-97d9-212e95762323 | error_deleting |        after-attch         |  9   |
| 31969c75-70fa-4719-be49-4af05e0df97b | b4c7df4e-0508-4e4f-86ff-6baee6975123 |     error      |           test5            |  7   |
| 6b0eab08-fd8a-434d-a7f9-9aca502ee192 | 80ea6146-9155-4b0e-8580-790d862e390e |     error      |       vol9_snapshot        |  40  |
| 7fedd82b-c2f0-45e7-a200-1e02d3342fa7 | a6c603c1-7ea6-4341-a514-a99ad5215668 |     error      |        from_image2         |  15  |
| 8a07e46d-7f36-443c-a36e-9e26e811cb32 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |   snapshot for vol_snap3   |  10  |
| e451bc81-b96c-495f-a64b-477489bc2d9f | 609d201e-f34a-4f7f-953c-3c1b5c087873 |     error      | create_from_vol_after_boot |  8   |
| f443126d-1408-4ce0-bfe7-d385b6fab797 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |          only_vol          |  10  |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
[root@cougar06 ~(keystone_admin)]# cinder snapshot-delete 6b0eab08-fd8a-434d-a7f9-9aca502ee192
[root@cougar06 ~(keystone_admin)]# cinder snapshot-list 
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
|                  ID                  |              Volume ID               |     Status     |        Display Name        | Size |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+
| 1264bdc0-fc0a-4817-976c-ce061a787d92 | 8e113c6f-f30c-4f6a-b511-2af507d7e758 | error_deleting |           test7            |  6   |
| 203b01c2-ac31-420f-a5e1-f12228c63ad1 | eafb3095-5b12-4ebb-97d9-212e95762323 | error_deleting |        after-attch         |  9   |
| 31969c75-70fa-4719-be49-4af05e0df97b | b4c7df4e-0508-4e4f-86ff-6baee6975123 |     error      |           test5            |  7   |
| 6b0eab08-fd8a-434d-a7f9-9aca502ee192 | 80ea6146-9155-4b0e-8580-790d862e390e | error_deleting |       vol9_snapshot        |  40  |
| 7fedd82b-c2f0-45e7-a200-1e02d3342fa7 | a6c603c1-7ea6-4341-a514-a99ad5215668 |     error      |        from_image2         |  15  |
| 8a07e46d-7f36-443c-a36e-9e26e811cb32 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |   snapshot for vol_snap3   |  10  |
| e451bc81-b96c-495f-a64b-477489bc2d9f | 609d201e-f34a-4f7f-953c-3c1b5c087873 |     error      | create_from_vol_after_boot |  8   |
| f443126d-1408-4ce0-bfe7-d385b6fab797 | 8ff451ff-2c35-467b-9104-3a16357ab66c | error_deleting |          only_vol          |  10  |
+--------------------------------------+--------------------------------------+----------------+----------------------------+------+


2013-12-12 13:29:41.895 3860 WARNING cinder.quota [req-0862cd5c-c642-4336-8b05-f7fb1890ad72 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Deprecated: Default quota for resource: volumes is set by the default quota flag: quota_volumes, it is now deprecated. Please use the the default quota class for default quota.
2013-12-12 13:41:15.353 3860 ERROR cinder.openstack.common.rpc.amqp [req-ace304ca-024e-4f0c-a1bf-1f13fca4ef7c 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Exception during message handling
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     **args)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 809, in wrapper
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     return func(self, *args, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 371, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     {'status': 'error'})
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 362, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     model_update = self.driver.create_snapshot(snapshot_ref)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 445, in create_snapshot
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp     raise exception.GlusterfsException(msg)
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: Timed out while waiting for Nova update for creation of snapshot 6b0eab08-fd8a-434d-a7f9-9aca502ee192.
2013-12-12 13:41:15.353 3860 TRACE cinder.openstack.common.rpc.amqp 
2013-12-12 13:51:57.704 3860 ERROR cinder.openstack.common.rpc.amqp [req-a24e1245-6bd9-47ef-a4f3-44ba100e3185 674776fc1eea47718301aeacbab072b3 5cea8d9e58c841dfb03b1cda755b539d] Exception during message handling
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     **args)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 809, in wrapper
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     return func(self, *args, **kwargs)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 424, in delete_snapshot
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     {'status': 'error_deleting'})
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 412, in delete_snapshot
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     self.driver.delete_snapshot(snapshot_ref)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 567, in delete_snapshot
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     snap_info = self._read_info_file(info_path)
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 528, in _read_info_file
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     return json.loads(self._read_file(info_path))
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 518, in _read_file
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp     with open(filename, 'r') as f:
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp IOError: [Errno 2] No such file or directory: u'/var/lib/cinder/mnt/249458a2755cd0a9f302b9d81eb3f35d/volume-80ea6146-9155-4b0e-8580-790d862e390e.info'
2013-12-12 13:51:57.704 3860 TRACE cinder.openstack.common.rpc.amqp 
(END)

Comment 5 Ayal Baron 2014-01-13 14:33:48 UTC
Eric, this is marked as test only, the dependent bug was moved to ON_QA, shouldn't this move back to ON_QA as well?

Comment 6 Eric Harney 2014-01-13 17:34:52 UTC
Tested on 2013.2.1-4.el6ost by killing Nova during the snapshot create process.  I was able to delete the snapshot.

This should have been fixed by the changes for bug 1033652.

Comment 7 Yogev Rabl 2014-01-15 12:43:59 UTC
This bug was not fixed: 

The scenario is:
1. created a volume from an image.
2. boot an instance from the volume.
3. took a snapshot of the instance.
4. deleted the snapshot.

The volume log show:

2014-01-15 11:41:51.680 6802 ERROR cinder.openstack.common.rpc.amqp [req-ac94d7c1-bd7b-4495-88bd-ca2f011d73c8 491e53ec606349d790265556c1de2f7f def147e4dce6439b9392f72ebaac0036] Exception during message handling
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     **args)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 820, in wrapper
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     return func(self, *args, **kwargs)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 424, in delete_snapshot
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     {'status': 'error_deleting'})
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 412, in delete_snapshot
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     self.driver.delete_snapshot(snapshot_ref)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 636, in delete_snapshot
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     online_delete_info)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 814, in _delete_snapshot_online
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp     raise exception.GlusterfsException(msg)
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: Timed out while waiting for Nova update for deletion of snapshot abe82a13-9fdd-4e9e-92f4-58cf7cf06037.
2014-01-15 11:41:51.680 6802 TRACE cinder.openstack.common.rpc.amqp

Comment 8 Eric Harney 2014-01-15 13:49:31 UTC
(In reply to Yogev Rabl from comment #7)
> This bug was not fixed: 
> 
> The scenario is:
> 1. created a volume from an image.
> 2. boot an instance from the volume.
> 3. took a snapshot of the instance.
> 4. deleted the snapshot.
> 

This is likely failing due to bug 1040711 -- not for the reasons that were addressed above.

This can be confirmed by looking at the Nova compute log at deletion time... it will show continued blockJobInfo calls for the same operation.

Comment 12 Yogev Rabl 2014-01-21 08:45:36 UTC
verified on version:
python-cinderclient-1.0.7-2.el6ost.noarch
openstack-cinder-2013.2.1-5.el6ost.noarch
python-cinder-2013.2.1-5.el6ost.noarch
libvirt-client-0.10.2-29.el6_5.2.x86_64
libvirt-0.10.2-29.el6_5.2.x86_64
python-novaclient-2.15.0-2.el6ost.noarch
python-nova-2013.2.1-2.el6ost.noarch
libvirt-python-0.10.2-29.el6_5.2.x86_64
openstack-nova-compute-2013.2.1-2.el6ost.noarch
openstack-nova-common-2013.2.1-2.el6ost.noarch

Comment 13 Bruce Reeler 2014-01-21 23:52:58 UTC
Setting requires_doc_text to "-", because this is a tracker bug.
It's "Depends on" bugs (1033652 1040711 1016798, above) all 3 have their own doc text which explains what the bugs fixed and this text is included in the Tech Notes.

Comment 16 Lon Hohberger 2014-02-04 17:19:46 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2014-0046.html


Note You need to log in before you can comment on or make changes to this bug.