failure in tempest.api.compute.servers.test_server_rescue_negative.ServerRescueNegativeTestJSON

[Angus Salkeld]

Unrelated test failure on review https://review.openstack.org/#/c/124661/

http://logs.openstack.org/61/124661/1/check/check-tempest-dsvm-full/8508921/

2014-09-29 05:37:00.904 | ==============================
2014-09-29 05:37:00.904 | Failed 1 tests - output below:
2014-09-29 05:37:00.904 | ==============================
2014-09-29 05:37:00.904 |
2014-09-29 05:37:00.904 | tearDownClass (tempest.api.compute.servers.test_server_rescue_negative.ServerRescueNegativeTestJSON)
2014-09-29 05:37:00.904 | ----------------------------------------------------------------------------------------------------
2014-09-29 05:37:00.904 |
2014-09-29 05:37:00.904 | Captured traceback:
2014-09-29 05:37:00.904 | ~~~~~~~~~~~~~~~~~~~
2014-09-29 05:37:00.904 | Traceback (most recent call last):
2014-09-29 05:37:00.905 | File "tempest/test.py", line 315, in tearDownClass
2014-09-29 05:37:00.905 | cls.resource_cleanup()
2014-09-29 05:37:00.905 | File "tempest/api/compute/servers/test_server_rescue_negative.py", line 59, in resource_cleanup
2014-09-29 05:37:00.905 | cls.delete_volume(cls.volume['id'])
2014-09-29 05:37:00.905 | File "tempest/api/compute/base.py", line 371, in delete_volume
2014-09-29 05:37:00.905 | cls._delete_volume(cls.volumes_extensions_client, volume_id)
2014-09-29 05:37:00.905 | File "tempest/api/compute/base.py", line 311, in _delete_volume
2014-09-29 05:37:00.905 | volumes_client.wait_for_resource_deletion(volume_id)
2014-09-29 05:37:00.905 | File "tempest/common/rest_client.py", line 577, in wait_for_resource_deletion
2014-09-29 05:37:00.905 | raise exceptions.TimeoutException(message)
2014-09-29 05:37:00.905 | TimeoutException: Request timed out
2014-09-29 05:37:00.905 | Details: (ServerRescueNegativeTestJSON:tearDownClass) Failed to delete resource 883746cd-2024-4665-a78f-293621e8f548 within the required time (196 s).
2014-09-29 05:37:00.906 |
2014-09-29 05:37:00.906 |
2014-09-29 05:37:00.906 |

[Ghanshyam Mann (ghanshyammann)]

Volume hanged in 'deleting' status on cinder side.

Volume - available -

2014-09-29 05:13:07.920 24731 INFO cinder.api.openstack.wsgi [req-47118e54-983a-4bfd-a18b-275386a1f588 b8d858f4aebb407b9d648304537d45c0 7a8f399eab3443e09688a46624298b17 - - -] GET http://127.0.0.1:8776/v1/7a8f399eab3443e09688a46624298b17/volumes/883746cd-2024-4665-a78f-293621e8f548
2014-09-29 05:13:07.920 24731 DEBUG cinder.api.openstack.wsgi [req-47118e54-983a-4bfd-a18b-275386a1f588 b8d858f4aebb407b9d648304537d45c0 7a8f399eab3443e09688a46624298b17 - - -] Empty body provided in request get_body /opt/stack/new/cinder/cinder/api/openstack/wsgi.py:789
2014-09-29 05:13:07.945 24731 INFO cinder.api.v1.volumes [req-47118e54-983a-4bfd-a18b-275386a1f588 b8d858f4aebb407b9d648304537d45c0 7a8f399eab3443e09688a46624298b17 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2014, 9, 29, 5, 13, 7), 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'883746cd-2024-4665-a78f-293621e8f548', 'size': 1L, 'user_id': u'b8d858f4aebb407b9d648304537d45c0', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': u'[<cinder.db.sqlalchemy.models.VolumeAdminMetadata object at 0x7f2c41d41c10>]', 'project_id': u'7a8f399eab3443e09688a46624298b17', 'launched_at': datetime.datetime(2014, 9, 29, 5, 11, 41), 'scheduled_at': datetime.datetime(2014, 9, 29, 5, 11, 40), 'status': u'available', 'volume_type_id': u'ac268553-305f-414d-b3e5-c3343f0e3d28', 'deleted': False, 'provider_location': u'127.0.0.1:3260,1 iqn.2010-10.org.openstack:volume-883746cd-2024-4665-a78f-293621e8f548 1', 'host': u'devstack-trusty-hpcloud-b4-2451331@lvmdriver-1#lvmdriver-1', 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': u'CHAP 3PmKkHygrnvSv5fMBoPx iGH3z8xmhmfC3cFQEk5o', 'display_name': u'ServerRescueNegativeTestJSON_volume-1818020912', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2014, 9, 29, 5, 11, 40), 'attach_status': u'detached', 'volume_type': <cinder.db.sqlalchemy.models.VolumeTypes object at 0x7f2c41a62a10>, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None, 'metadata': {u'readonly': u'False'}}
2014-09-29 05:13:08.027 24731 INFO cinder.api.openstack.wsgi [req-47118e54-983a-4bfd-a18b-275386a1f588 b8d858f4aebb407b9d648304537d45c0 7a8f399eab3443e09688a46624298b17 - - -] http://127.0.0.1:8776/v1/7a8f399eab3443e09688a46624298b17/volumes/883746cd-2024-4665-a78f-293621e8f548 returned with HTTP 200
2014-09-29 05:13:08.028 24731 INFO eventlet.wsgi.server [req-47118e54-983a-4bfd-a18b-275386a1f588 b8d858f4aebb407b9d648304537d45c0 7a8f399eab3443e09688a46624298b17 - - -] 127.0.0.1 - - [29/Sep/2014 05:13:08] "GET /v1/7a8f399eab3443e09688a46624298b17/volumes/883746cd-2024-4665-a78f-293621e8f548 HTTP/1.1" 200 825 0.109936
2014-09-29 05:13:08.169 24731 INFO eventlet.wsgi.server [-] (24731) accepted ('127.0.0.1', 42881)

Delete request -

2014-09-29 05:13:08.209 24731 INFO cinde...