Bug 1090116
| Summary: | [RHS-RHOS]: fail to delete snapshot after reset-state with GlusterfsException: No base file found | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | Dafna Ron <dron> | ||||||
| Component: | openstack-cinder | Assignee: | Eric Harney <eharney> | ||||||
| Status: | CLOSED WONTFIX | QA Contact: | Dafna Ron <dron> | ||||||
| Severity: | high | Docs Contact: | |||||||
| Priority: | high | ||||||||
| Version: | 4.0 | CC: | dron, eharney, scohen, sgotliv, yeylon | ||||||
| Target Milestone: | --- | Keywords: | ZStream | ||||||
| Target Release: | 5.0 (RHEL 7) | ||||||||
| Hardware: | x86_64 | ||||||||
| OS: | Linux | ||||||||
| Whiteboard: | storage | ||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: | ||||||||
| Last Closed: | 2015-08-25 09:44:29 UTC | Type: | Bug | ||||||
| Regression: | --- | Mount Type: | --- | ||||||
| Documentation: | --- | CRM: | |||||||
| Verified Versions: | Category: | --- | |||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||
| Embargoed: | |||||||||
| Attachments: |
|
||||||||
If I detach the volume from the instance -> reset the state -> try to delete again we fail with a different error:
2014-04-22 19:03:00.316 2233 ERROR cinder.openstack.common.rpc.amqp [req-6ca744d3-c0e4-453f-b88a-0a7a2fd0194e 97e5450b24624fd78ad6fa6d8a14ef3d c3178ebef2c24d1b9a045bd67483a83c] Exception during message handling
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2014-04-22 19:03:00.316 2233 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-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp **args)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 435, in delete_snapshot
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp {'status': 'error_deleting'})
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp self.gen.next()
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 423, in delete_snapshot
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp self.driver.delete_snapshot(snapshot_ref)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp retval = f(*args, **kwargs)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 557, in delete_snapshot
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp self._delete_snapshot(snapshot)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 664, in _delete_snapshot
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp self._qemu_img_commit(snapshot_path)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 877, in _qemu_img_commit
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp return self._execute('qemu-img', 'commit', path, run_as_root=True)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 142, in execute
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp return processutils.execute(*cmd, **kwargs)
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/processutils.py", line 173, in execute
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp cmd=' '.join(cmd))
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp ProcessExecutionError: Unexpected error while running command.
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf qemu-img commit /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.
bb2fa5f1-4df4-4a62-b077-0a10d862c6fa
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp Exit code: 1
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp Stdout: ''
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp Stderr: 'Image is already committed\n'
2014-04-22 19:03:00.316 2233 TRACE cinder.openstack.common.rpc.amqp
2014-04-22 19:03:03.169 2233 DEBUG qpid.messaging.io.raw [-] READ[3b385a8]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416
2014-04-22 19:03:03.170 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3b385a8]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654
2014-04-22 19:03:04.885 2233 DEBUG qpid.messaging.io.raw [-] READ[3e0f710]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416
2014-04-22 19:03:04.886 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3e0f710]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654
2014-04-22 19:03:20.202 2233 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.6/site-packages/cinder/openstack/common/periodic_task.py:1
76
Created attachment 888555 [details]
volumes.log after detach
|
Created attachment 888551 [details] logs Description of problem: after failing to delete a snapshot on timeout, I tried to reset the snapshot state and try to delete again. at which point we fail to delete the snapshot with the following error: 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: No base file found for /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa. Version-Release number of selected component (if applicable): How reproducible: 100% Steps to Reproduce: 1. configure cinder to work with gluster backend 2. create a 10G volume 3. attach the volume to an instance 4. create a snapshot using --force true 5. try to delete the snapshot 6. when failing on timeout, reset the snapshot status and try to delete again Actual results: after the first failure we are failing to delete the snapshot with the following error: 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: No base file found for /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa. Expected results: we should be able to try and delete again. Additional info: 2014-04-22 18:25:48.507 2233 DEBUG qpid.messaging.io.raw [-] SENT[3e0f710]: '\x0f\x00\x00:\x00\x00\x00\x00\x00\x00\x00\x00\x02\x01\x01\x00\x00(e20240e0-4cca-44eb-8847-cc486fa240fa:357\x0f\x00\x00\x1c\x00\x00\x00\x00\x00\x00\x00\x00\x02\x07\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' writeable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:480 2014-04-22 18:25:48.508 2233 DEBUG qpid.messaging.io.raw [-] READ[3e0f710]: '\x0f\x00\x00:\x00\x00\x00\x00\x00\x00\x00\x00\x02\x02\x01\x00\x00(e20240e0-4cca-44eb-8847-cc486fa240fa:357\x0f\x00\x00\x1c\x00\x00\x00\x00\x00\x00\x00\x00\x02\x07\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416 2014-04-22 18:25:48.509 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3e0f710]: SessionAttached(name='e20240e0-4cca-44eb-8847-cc486fa240fa:357') write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654 2014-04-22 18:25:48.509 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3e0f710]: SessionCommandPoint(command_id=serial(0), command_offset=0) write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654 2014-04-22 18:25:48.741 2233 ERROR cinder.openstack.common.rpc.amqp [req-ebe13b37-9fb4-496b-8869-cff771b9cd60 97e5450b24624fd78ad6fa6d8a14ef3d c3178ebef2c24d1b9a045bd67483a83c] Exception during message handling 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last): 2014-04-22 18:25:48.741 2233 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-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp **args) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 435, in delete_snapshot 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp {'status': 'error_deleting'}) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__ 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp self.gen.next() 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 423, in delete_snapshot 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp self.driver.delete_snapshot(snapshot_ref) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/lockutils.py", line 247, in inner 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp retval = f(*args, **kwargs) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 557, in delete_snapshot 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp self._delete_snapshot(snapshot) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/glusterfs.py", line 621, in _delete_snapshot 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp raise exception.GlusterfsException(msg) 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp GlusterfsException: No base file found for /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa. 2014-04-22 18:25:48.741 2233 TRACE cinder.openstack.common.rpc.amqp 2014-04-22 18:26:03.171 2233 DEBUG qpid.messaging.io.raw [-] READ[3b385a8]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416 2014-04-22 18:26:03.172 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3b385a8]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654 2014-04-22 18:26:04.888 2233 DEBUG qpid.messaging.io.raw [-] READ[3e0f710]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416 2014-04-22 18:26:04.888 2233 DEBUG qpid.messaging.io.ops [-] RCVD[3e0f710]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654 2014-04-22 18:26:07.577 2233 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.6/site-packages/cinder/openstack/common/periodic_task.py:176 [root@orange-vdsf ~(keystone_admin)]# ls -l /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa -rw-r--r--. 1 qemu qemu 10739843072 Apr 22 18:21 /var/lib/cinder/mnt/59ed8cb64fc8948968a29181234051a2/volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa [root@orion Dafna]# ls -l |grep c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d -rw-r--r-- 2 qemu qemu 10739843072 Apr 22 18:21 volume-c2d7b4c3-d9ef-4676-975b-fb7c83fe3927.bb2fa5f1-4df4-4a62-b077-0a10d862c6fa