Volume cmd failed by Service Unavailable

[Peng Peng]

Brief Description
-----------------
During test suite, volume cmd stopped working for 4 mins, then recovered by itself.

Severity
--------
Major

Steps to Reproduce
------------------
run Volume related cmd, like volume list, volume show etc

TC-name: networking/test_ping_vms.py::test_ping_between_two_vms[tis-centos-guest-virtio-virtio]

Expected Behavior
------------------

Actual Behavior
----------------

Reproducibility
---------------
Seen once

System Configuration
--------------------
One node system

Lab-name: SM-3

Branch/Pull Time/Commit
-----------------------
stx master as of 20190719T013000Z

Last Pass
---------
20190715T233000Z

Timestamp/Logs
--------------
[2019-07-19 14:10:23,917] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a'
[2019-07-19 14:10:28,077] 423 DEBUG MainThread ssh.expect :: Output:

[sysadmin@controller-0 ~(keystone_admin)]$

[2019-07-19 14:10:28,184] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume create --bootable --image=9d38579a-f25c-4053-bd78-e9933990df45 --size=2 vol-tis-centos-guest-1'
[2019-07-19 14:10:34,239] 423 DEBUG MainThread ssh.expect :: Output:
+---------------------+--------------------------------------+
| Field | Value |
+---------------------+--------------------------------------+
| attachments | [] |

[2019-07-19 14:10:43,520] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume show 98b8cce5-3ad1-41b3-8748-6eff3e7f97ca'
[2019-07-19 14:10:47,282] 423 DEBUG MainThread ssh.expect :: Output:
Service Unavailable (HTTP 503)
[sysadmin@controller-0 ~(keystone_admin)]$

[2019-07-19 14:10:53,898] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a'
[2019-07-19 14:10:55,028] 423 DEBUG MainThread ssh.expect :: Output:
Failed to discover available identity versions when contacting http://keystone.openstack.svc.cluster.local/v3. Attempting to parse version from URL.
Service Unavailable (HTTP 503)
[sysadmin@controller-0 ~(keystone_admin)]$

[2019-07-19 14:11:04,482] 186 ERROR MainThread resource_mgmt._delete_resources:: ERROR: Failed to delete resource(s).
Details: ["CLI command is rejected.\nDetails: CLI 'openstack --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a' failed to execute. Output: Failed to discover available identity versions when contacting http://keystone.openstack.svc.cluster.local/v3. Attempting to parse version from URL.\nService Unavailable (HTTP 503)"]

[2019-07-19 14:14:44,789] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a'
[2019-07-19 14:14:47,248] 423 DEBUG MainThread ssh.expect :: Output:
+--------------------------------------+------------------------+-----------+------+------+----------+-------------+------------+
| ID | Name | Status | Size | Type | Bootable | Attached to | Properties |
+--------------------------------------+------------------------+-----------+------+------+----------+-------------+------------+
| 98b8cce5-3ad1-41b3-8748-6eff3e7f97ca | vol-tis-centos-guest-1 | available | 2 | None | true | | |
+--------------------------------------+------------------------+-----------+------+------+----------+-------------+------------+
[sysadmin@controller-0 ~(keystone_admin)]$

Test Activity
-------------
Sanity

[Frank Miller (sensfan22)]

From the cinder-volume logs can see that the volume was created successfully:

{"log":"2019-07-19 14:10:36.795 17 INFO cinder.volume.flows.manager.create_volume [req-c48e9eff-9277-4856-87b3-93db17635d2a 4306f8d8d83742bfb8ba6a100596a0ec 3ac59614e7784e2da9dd04fd88a825f6 - default default] Volume 98b8cce5-3ad1-41b3-8748-6eff3e7f97ca: being created as image with specification: {'status': u'creating', 'image_location': (u'rbd://7a5ed103-91d1-45e0-abdd-2b21ffc6c000/images/9d38579a-f25c-4053-bd78-e9933990df45/snap', None), 'volume_size': 2, 'volume_name': u'98b8cce5-3ad1-41b3-8748-6eff3e7f97ca', 'image_id': u'9d38579a-f25c-4053-bd78-e9933990df45', 'image_service': \u003ccinder.image.glance.GlanceImageService object at 0x7f7a908787d0\u003e, 'image_meta': {u'container_format': u'bare', u'min_ram': 0, u'updated_at': datetime.datetime(2019, 7, 19, 7, 37, 30, tzinfo=\u003ciso8601.Utc\u003e), u'file': u'/v2/images/9d38579a-f25c-4053-bd78-e9933990df45/file', u'owner': u'dcc20d889db34b30bbf720c33ea06471', u'id': u'9d38579a-f25c-4053-bd78-e9933990df45', u'size': 1611581440, u'disk_format': u'raw', u'os_hash_algo': u'sha512', u'direct_url': u'rbd://7a5ed103-91d1-45e0-abdd-2b21ffc6c000/images/9d38579a-f25c-4053-bd78-e9933990df45/snap', u'status': u'active', u'tags': [], u'visibility': u'public', u'min_disk': 0, u'virtual_size': None, 'properties': {}, u'name': u'tis-centos-guest', u'checksum': u'b0e308015909fd2ac4c7472e19f149de', u'created_at': datetime.datetime(2019, 7, 19, 7, 36, 56, tzinfo=\u003ciso8601.Utc\u003e), u'os_hidden': False, u'protected': False, u'os_hash_value': u'265b109b030b3b903ff7db541fdc4d15c667da07a8e4372b51ac6a1c840389f7acb21a1e942838fe8fec1cf5c9190f27e4e65c8d145b8a9a1346a06ff7c789f6'}}\n","stream":"stdout","time":"2019-07-19T14:10:36.796619748Z"}

{"log":"2019-07-19 14:10:44.911 17 INFO cinder.volume.manager [req-c48e9eff-9277-4856-87b3-93db17635d2a 4306f8d8d83742bfb8ba6a100596a0ec 3ac59614e7784e2da9dd04fd88a825f6 - default default] Created volume successfully.\n","stream":"stdout","time":"2019-07-19T14:10:44.912803166Z"}

The issue does not appear to be a cinder issue but an issue contacting keystone based on this error message:
Failed to discover available identity versions when contacting http://keystone.openstack.svc.cluster.local/v3. Attempting to parse version from URL.
Service Unavailable (HTTP 503)

[Ghada Khalil (gkhalil)]

As per input from Frank Miller and Brent Rowsell, this should be considered a high priority given there has been a number of bugs reporting pod/msging stability issues. Marking as stx.2.0 gating.

[Tao Liu (tliu88)]

The log attached does not appear to be from SM-3. We need to reproduce the problem for further investigation.

[Tao Liu (tliu88)]

So far this problem it has not been reproduced.

[Frank Miller (sensfan22)]

Changing importance to medium since command recovered on its own.

[Dariush Eslimi (deslimi)]

Assigning to originator for reproduction and providing the correct logs.

[Peng Peng (ppeng)]

Issue was reproduced on SM-3 and load 2019-08-12_20-59-00

[2019-08-13 13:02:20,097] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume create --size=2 --image=2da666a2-3d0a-4317-9532-b61c09e7039a --bootable vol-tis-centos-guest-1'
[2019-08-13 13:02:23,730] 423 DEBUG MainThread ssh.expect :: Output:
+---------------------+--------------------------------------+
| Field | Value |
+---------------------+--------------------------------------+
| attachments | [] |

[2019-08-13 13:03:20,186] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'tenant1' --os-password 'Li69nux*' --os-project-name tenant1 --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a'
[2019-08-13 13:05:30,331] 423 DEBUG MainThread ssh.expect :: Output:
Unable to establish connection to http://cinder-api.openstack.svc.cluster.local:8776/v2/3b976e1069b948c4bb63939e25bc73a1/volumes/detail?all_tenants=True: HTTPConnectionPool(host='cinder-api.openstack.svc.cluster.local', port=8776): Max retries exceeded with url: /v2/3b976e1069b948c4bb63939e25bc73a1/volumes/detail?all_tenants=True (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f47bbc62d90>: Failed to establish a new connection: [Errno 110] Connection timed out',))

[2019-08-13 13:06:13,750] 301 DEBUG MainThread ssh.send :: Send 'openstack --os-username 'admin' --os-password 'Li69nux*' --os-project-name admin --os-auth-url http://keystone.openstack.svc.cluster.local/v3 --os-user-domain-name Default --os-project-domain-name Default --os-identity-api-version 3 --os-interface internal --os-region-name RegionOne volume list --long --a'
[2019-08-13 13:06:19,998] 423 DEBUG MainThread ssh.expect :: Output:
+--------------------------------------+------------------------+-----------+------+------------+----------+-------------+------------+
| ID | Name | Status | Size | Type | Bootable | Attached to | Properties |
+--------------------------------------+------------------------+-----------+------+------------+----------+-------------+------------+
| b69dcef6-ed43-432b-b3ce-d7b7bb4e4068 | vol-tis-centos-guest-1 | available | 2 | ceph-store | true | | |
+--------------------------------------+------------------------+-----------+------+------------+----------+-------------+------------+

[Ghada Khalil (gkhalil)]

As per agreement with the community, moving all unresolved medium priority bugs from stx.2.0 to stx.3.0

[Peng Peng (ppeng)]

Issue was not reproduced on train
2019-11-21_20-00-00
wcp_3-6

[Ghada Khalil (gkhalil)]

Closing; as per above, issue is not reproduced in train