Test case “tempest.api.volume.test_image_metadata.VolumesImageMetadata” failing on both FC and iSCSI
Logs URL :
FC : http://54.201.44.218/69/585069/3/check/3par-fc-driver-master-client-pip-ssa02-dsvm/3dbdd5c/
ISCSI : http://54.201.44.218/69/585069/3/check/3par-iscsi-driver-master-client-pip-ssa02-dsvm/8d70521/
Error :
ft1.1: tearDownClass (tempest.api.volume.test_image_metadata.VolumesImageMetadata)_StringException: Traceback (most recent call last):
File "tempest/test.py", line 224, in tearDownClass
six.reraise(etype, value, trace)
File "tempest/test.py", line 196, in tearDownClass
teardown()
File "tempest/test.py", line 562, in resource_cleanup
raise testtools.MultipleExceptions(*cleanup_errors)
testtools.runtest.MultipleExceptions: (<class 'tempest.lib.exceptions.DeleteErrorException'>, Resource 695a211e-fd8b-4134-9813-98226e3ba5b1 failed to delete and is in ERROR status, <traceback object at 0x7f009ab9a320>)
Log grep on testcase (grep based on testcase, volume id and http-request attached)
root@ansible-es:/tmp# grep tempest-VolumesImageMetadata-631068744 screen-c-vol.txt.gz
Jul 24 18:14:23.619544 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.flows.manager.create_volume [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Volume reschedule parameters: True retry: {u'num_attempts': 1, u'backends': [u'd-p-c-fc-p74fc-2387228@dot#fc-p74fc-2387228_b5477'], u'hosts': [u'd-p-c-fc-p74fc-2387228@dot#fc-p74fc-2387228_b5477']} {{(pid=12774) get_flow /opt/stack/new/cinder/cinder/volume/flows/manager/create_volume.py:1171}}
Jul 24 18:14:23.624235 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING stevedore.named [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Could not load cinder.keymgr.conf_key_mgr.ConfKeyManager
Jul 24 18:14:23.624534 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING castellan.key_manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Deprecation Warning : cinder.keymgr.conf_key_mgr.ConfKeyManager is not a stevedore based driver, trying to load it as a class: NoMatches: No 'castellan.drivers' driver found, looking for 'cinder.keymgr.conf_key_mgr.ConfKeyManager'
Jul 24 18:14:23.634857 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Flow 'volume_create_manager' (ff96ce5b-0193-4df9-90cf-c0ae7dfe988a) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _flow_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:145}}
Jul 24 18:14:23.636997 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (4c1c863d-0580-42b6-88d1-94df0268366a) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194}}
Jul 24 18:14:23.657346 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG oslo_db.sqlalchemy.engines [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION {{(pid=12774) _check_effective_sql_mode /usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:308}}
Jul 24 18:14:23.676566 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (4c1c863d-0580-42b6-88d1-94df0268366a) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'Volume(_name_id=None,admin_metadata=<?>,attach_status='detached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2018-07-24T18:14:23Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-VolumesImageMetadata-Volume-397844978',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='d-p-c-fc-p74fc-2387228@dot#fc-p74fc-2387228_b5477',id=695a211e-fd8b-4134-9813-98226e3ba5b1,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='472ce036faa44b11865f5716fba614f6',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2018-07-24T18:14:24Z,service_uuid=None,shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='creating',terminated_at=None,updated_at=2018-07-24T18:14:24Z,user_id='2f6c8ea9a9ae45d7a58a7d0f89286235',volume_attachment=<?>,volume_type=VolumeType(523cc129-d758-4748-9dc5-66b83ed7fdd2),volume_type_id=523cc129-d758-4748-9dc5-66b83ed7fdd2)' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:183}}
Jul 24 18:14:23.678433 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (3b3f8250-5def-4b81-b084-bca3a1be2949) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194}}
Jul 24 18:14:23.679897 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (3b3f8250-5def-4b81-b084-bca3a1be2949) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:183}}
Jul 24 18:14:23.681210 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (419f8954-7b3b-4ae4-a199-3e438cb2e28a) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194}}
Jul 24 18:14:23.771773 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (419f8954-7b3b-4ae4-a199-3e438cb2e28a) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'status': u'creating', 'image_location': (None, None), 'image_id': u'97bb3e99-262e-4d10-b9bb-4b2a72a2ff77', 'volume_id': u'695a211e-fd8b-4134-9813-98226e3ba5b1', 'volume_size': 1, 'image_service': <cinder.image.glance.GlanceImageService object at 0x7f05cbdd0810>, 'image_meta': {u'status': u'active', u'name': u'cirros-0.3.5-x86_64-disk', u'tags': [], u'container_format': u'bare', u'created_at': datetime.datetime(2018, 7, 24, 17, 48, 57, tzinfo=<iso8601.Utc>), u'disk_format': u'qcow2', u'updated_at': datetime.datetime(2018, 7, 24, 17, 48, 58, tzinfo=<iso8601.Utc>), u'visibility': u'public', 'properties': {}, u'owner': u'9c10eb4836bc46bdbb45bb5de406dfb0', u'protected': False, u'id': u'97bb3e99-262e-4d10-b9bb-4b2a72a2ff77', u'file': u'/v2/images/97bb3e99-262e-4d10-b9bb-4b2a72a2ff77/file', u'checksum': u'f8ab98ff5e73ebab884d80c9dc9c7290', u'min_disk': 0, u'virtual_size': None, u'min_ram': 0, u'size': 13267968}, 'volume_name': u'volume-695a211e-fd8b-4134-9813-98226e3ba5b1', 'type': 'image'}' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:183}}
Jul 24 18:14:23.773535 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (7e1a5e72-9da0-47e4-9869-2df115badbd2) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194}}
Jul 24 18:14:23.776170 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (7e1a5e72-9da0-47e4-9869-2df115badbd2) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:183}}
Jul 24 18:14:23.777951 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.manager [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (3fb953cd-47e0-4b98-89c0-ea3286b59f4e) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=12774) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194}}
Jul 24 18:14:23.778613 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: INFO cinder.volume.flows.manager.create_volume [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Volume 695a211e-fd8b-4134-9813-98226e3ba5b1: being created as image with specification: {'status': u'creating', 'image_location': (None, None), 'volume_size': 1, 'volume_name': u'volume-695a211e-fd8b-4134-9813-98226e3ba5b1', 'image_id': u'97bb3e99-262e-4d10-b9bb-4b2a72a2ff77', 'image_service': <cinder.image.glance.GlanceImageService object at 0x7f05cbdd0810>, 'image_meta': {u'status': u'active', u'name': u'cirros-0.3.5-x86_64-disk', u'tags': [], u'container_format': u'bare', u'created_at': datetime.datetime(2018, 7, 24, 17, 48, 57, tzinfo=<iso8601.Utc>), u'disk_format': u'qcow2', u'updated_at': datetime.datetime(2018, 7, 24, 17, 48, 58, tzinfo=<iso8601.Utc>), u'visibility': u'public', 'properties': {}, u'owner': u'9c10eb4836bc46bdbb45bb5de406dfb0', u'protected': False, u'id': u'97bb3e99-262e-4d10-b9bb-4b2a72a2ff77', u'file': u'/v2/images/97bb3e99-262e-4d10-b9bb-4b2a72a2ff77/file', u'checksum': u'f8ab98ff5e73ebab884d80c9dc9c7290', u'min_disk': 0, u'virtual_size': None, u'min_ram': 0, u'size': 13267968}}
Jul 24 18:14:23.779357 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.flows.manager.create_volume [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Cloning 695a211e-fd8b-4134-9813-98226e3ba5b1 from image 97bb3e99-262e-4d10-b9bb-4b2a72a2ff77 at location (None, None). {{(pid=12774) _create_from_image /opt/stack/new/cinder/cinder/volume/flows/manager/create_volume.py:894}}
Jul 24 18:14:23.790486 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.coordination [None req-c9f3990a-d241-41a9-a87c-5d447bff2282 tempest-VolumesImageMetadata-631068744 None] Lock "cinder-97bb3e99-262e-4d10-b9bb-4b2a72a2ff77" acquired by "_prepare_image_cache_entry" :: waited 0.010s {{(pid=12774) _synchronized /opt/stack/new/cinder/cinder/coordination.py:150}}
Jul 24 18:14:26.327384 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.coordination [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Lock "cinder-695a211e-fd8b-4134-9813-98226e3ba5b1-delete_volume" acquired by "delete_volume" :: waited 0.015s {{(pid=12774) _synchronized /opt/stack/new/cinder/cinder/coordination.py:150}}
Jul 24 18:14:26.392811 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.drivers.hpe.hpe_3par_fc [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] ==> delete_volume: call {'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='nova',bootable=True,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2018-07-24T18:14:23Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-VolumesImageMetadata-Volume-397844978',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='d-p-c-fc-p74fc-2387228@dot#fc-p74fc-2387228_b5477',id=695a211e-fd8b-4134-9813-98226e3ba5b1,launched_at=2018-07-24T18:14:25Z,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='472ce036faa44b11865f5716fba614f6',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2018-07-24T18:14:24Z,service_uuid='d8592973-6aa1-4615-81b7-dc4301fb5bc1',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='deleting',terminated_at=2018-07-24T18:14:26Z,updated_at=2018-07-24T18:14:26Z,user_id='2f6c8ea9a9ae45d7a58a7d0f89286235',volume_attachment=<?>,volume_type=VolumeType(523cc129-d758-4748-9dc5-66b83ed7fdd2),volume_type_id=523cc129-d758-4748-9dc5-66b83ed7fdd2), 'self': <cinder.volume.drivers.hpe.hpe_3par_fc.HPE3PARFCDriver object at 0x7f05cc9ed050>} {{(pid=12774) trace_logging_wrapper /opt/stack/new/cinder/cinder/utils.py:914}}
Jul 24 18:14:26.394505 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None]
Jul 24 18:14:26.434216 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING py.warnings [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] /usr/local/lib/python2.7/dist-packages/urllib3/connectionpool.py:857: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
Jul 24 18:14:26.442108 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP:{'status': '200'
Jul 24 18:14:26.445541 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP BODY:{"major":1,"minor":6,"revision":2,"build":30301410}
Jul 24 18:14:26.446813 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None]
Jul 24 18:14:26.482123 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING py.warnings [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] /usr/local/lib/python2.7/dist-packages/urllib3/connectionpool.py:857: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
Jul 24 18:14:26.487424 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP:{'status': '200'
Jul 24 18:14:26.490729 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP BODY:{"major":1,"minor":6,"revision":2,"build":30301410}
Jul 24 18:14:26.491358 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.drivers.hpe.hpe_3par_common [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Connecting to 3PAR {{(pid=12774) client_login /opt/stack/new/cinder/cinder/volume/drivers/hpe/hpe_3par_common.py:378}}
Jul 24 18:14:26.492027 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None]
Jul 24 18:14:26.493386 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] REQ BODY: {"password": "sanitized", "user": "edit3par"}
Jul 24 18:14:26.524542 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING py.warnings [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] /usr/local/lib/python2.7/dist-packages/urllib3/connectionpool.py:857: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
Jul 24 18:14:26.534985 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP:{'status': '201'
Jul 24 18:14:26.538497 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP BODY:{"key":"0-eaa38b1021a22a98b8dec0f0a1cc3e0d-0b6d575b"}
Jul 24 18:14:26.549299 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None]
Jul 24 18:14:26.587880 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING py.warnings [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] /usr/local/lib/python2.7/dist-packages/urllib3/connectionpool.py:857: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
Jul 24 18:14:26.605400 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP:{'status': '409'
Jul 24 18:14:26.608207 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP BODY:{"code":151,"desc":"invalid operation: Volume tuning is in progress"}
Jul 24 18:14:44.211151 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG paramiko.transport [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] [chan 0] Max packet in: 32768 bytes {{(pid=12774) _log /usr/local/lib/python2.7/dist-packages/paramiko/channel.py:1184}}
Jul 24 18:14:44.637064 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR cinder.volume.drivers.hpe.hpe_3par_common [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.: HTTPConflict: Conflict (HTTP 409) 151 - invalid operation: Volume tuning is in progress
Jul 24 18:14:44.642134 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR cinder.volume.drivers.hpe.hpe_3par_common [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Exception: The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.: VolumeIsBusy: The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.
Jul 24 18:14:44.642464 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.drivers.hpe.hpe_3par_common [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Disconnect from 3PAR REST and SSH 9d62fc0b-3df7-4c0e-8c1b-6af9d058007f {{(pid=12774) client_logout /opt/stack/new/cinder/cinder/volume/drivers/hpe/hpe_3par_common.py:402}}
Jul 24 18:14:44.643307 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None]
Jul 24 18:14:44.678271 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: WARNING py.warnings [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] /usr/local/lib/python2.7/dist-packages/urllib3/connectionpool.py:857: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
Jul 24 18:14:44.683386 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP:{'status': '200'
Jul 24 18:14:44.686746 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG hpe3parclient.http [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] RESP BODY:
Jul 24 18:14:44.746892 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.volume.drivers.hpe.hpe_3par_fc [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] <== delete_volume: exception (18352ms) CinderException(u'The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.',) {{(pid=12774) trace_logging_wrapper /opt/stack/new/cinder/cinder/utils.py:924}}
Jul 24 18:14:44.772334 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: DEBUG cinder.coordination [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Lock "cinder-695a211e-fd8b-4134-9813-98226e3ba5b1-delete_volume" released by "delete_volume" :: held 18.445s {{(pid=12774) _synchronized /opt/stack/new/cinder/cinder/coordination.py:162}}
Jul 24 18:14:44.850586 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server [None req-a25a1e1f-a8f3-4e8c-993c-5aa2dad0db92 tempest-VolumesImageMetadata-631068744 None] Exception during message handling: CinderException: The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.
<trace>
Jul 24 18:14:44.851241 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server Traceback (most recent call last):
Jul 24 18:14:44.851714 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
Jul 24 18:14:44.852052 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
Jul 24 18:14:44.852373 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 265, in dispatch
Jul 24 18:14:44.852750 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
Jul 24 18:14:44.853118 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
Jul 24 18:14:44.853851 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
Jul 24 18:14:44.853993 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "<decorator-gen-490>", line 2, in delete_volume
Jul 24 18:14:44.854163 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/coordination.py", line 151, in _synchronized
Jul 24 18:14:44.854321 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server return f(*a, **k)
Jul 24 18:14:44.854478 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "<decorator-gen-489>", line 2, in delete_volume
Jul 24 18:14:44.854634 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/objects/cleanable.py", line 207, in wrapper
Jul 24 18:14:44.854807 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
Jul 24 18:14:44.854973 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/volume/manager.py", line 833, in delete_volume
Jul 24 18:14:44.855199 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server new_status)
Jul 24 18:14:44.855353 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
Jul 24 18:14:44.855576 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server self.force_reraise()
Jul 24 18:14:44.855750 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
Jul 24 18:14:44.855931 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
Jul 24 18:14:44.856074 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/volume/manager.py", line 815, in delete_volume
Jul 24 18:14:44.856241 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server self.driver.delete_volume(volume)
Jul 24 18:14:44.856398 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/utils.py", line 918, in trace_logging_wrapper
Jul 24 18:14:44.856557 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
Jul 24 18:14:44.857343 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/volume/drivers/hpe/hpe_3par_base.py", line 159, in delete_volume
Jul 24 18:14:44.857592 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server common.delete_volume(volume)
Jul 24 18:14:44.857802 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server File "/opt/stack/new/cinder/cinder/volume/drivers/hpe/hpe_3par_common.py", line 2570, in delete_volume
Jul 24 18:14:44.858015 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server raise exception.CinderException(ex)
Jul 24 18:14:44.858230 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server CinderException: The volume is currently busy on the 3PAR and cannot be deleted at this time. You can try again later.
Jul 24 18:14:44.858455 d-p-c-fc-p74fc-2387228 cinder-volume[12680]: ERROR oslo_messaging.rpc.server
</trace>
Fix proposed to branch: master
Review: https:/