Bug 1602309

Created attachment 1459663 [details]
cinder-log

Adding RPM :
on client side :
puppet-cinder-12.4.1-0.20180329071637.4011a82.el7ost.noarch
python2-cinderclient-3.5.0-1.el7ost.noarch



on controller:
[heat-admin@controller-0 ~]$ sudo rpm -qa | grep cinder
python-cinder-12.0.1-0.20180418194614.c476898.el7ost.noarch
python2-cinderclient-3.5.0-1.el7ost.noarch
openstack-cinder-12.0.1-0.20180418194614.c476898.el7ost.noarch
puppet-cinder-12.4.1-0.20180329071637.4011a82.el7ost.noarch




Client retype debug:  (exected to fail)

(undercloud) [stack@undercloud-0 ~]$ source overcloudrc 
(overcloud) [stack@undercloud-0 ~]$ cinder --debug retype 7793ab23-2160-4f41-87fc-e7da8bd12914 lvm --migration-policy on-demand
DEBUG:keystoneauth.session:REQ: curl -g -i -X GET http://10.0.0.110:5000//v3 -H "Accept: application/json" -H "User-Agent: cinder keystoneauth1/3.4.0 python-requests/2.14.2 CPython/2.7.5"
DEBUG:keystoneauth.session:RESP: [200] Date: Wed, 18 Jul 2018 07:31:07 GMT Server: Apache Vary: X-Auth-Token,Accept-Encoding x-openstack-request-id: req-38258dea-86a2-45b8-9a08-febff976c803 Content-Encoding: gzip Content-Length: 192 Content-Type: application/json 
RESP BODY: {"version": {"status": "stable", "updated": "2018-02-28T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.10", "links": [{"href": "http://10.0.0.110:5000/v3/", "rel": "self"}]}}

DEBUG:keystoneauth.session:GET call to None for http://10.0.0.110:5000//v3 used request id req-38258dea-86a2-45b8-9a08-febff976c803
DEBUG:keystoneauth.identity.v3.base:Making authentication request to http://10.0.0.110:5000/v3/auth/tokens
DEBUG:keystoneauth.identity.v3.base:{"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "de88e638105e4efbbc976daedc25124a", "name": "admin"}], "expires_at": "2018-07-18T08:31:07.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "878c14e41152445d9065d7cdf87537b2", "name": "admin"}, "catalog": [{"endpoints": [{"url": "http://172.17.1.17:9311", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "0d7b215c91664734a2988aacc9166056"}, {"url": "http://10.0.0.110:9311", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "849aa1b0493a4f31918051c1bf54f0aa"}, {"url": "http://172.17.1.17:9311", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "e8fb4a79956844b2b671d9612aecd2ed"}], "type": "key-manager", "id": "0e757309bdea4819b470fa8a438d953d", "name": "barbican"}, {"endpoints": [{"url": "http://10.0.0.110:9292", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "0165509840fb404cb0c6bfd9e5de8929"}, {"url": "http://172.17.1.17:9292", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "2260a9436f0d423098e2cf254538028c"}, {"url": "http://172.17.1.17:9292", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "25a9679265354b2e937d3ed9bdeb7939"}], "type": "image", "id": "21d2db8feb8349b49e3c123588581379", "name": "glance"}, {"endpoints": [{"url": "http://10.0.0.110:8042", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "60b4d2b649234c349e81d1e368cfb2c0"}, {"url": "http://172.17.1.17:8042", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "6711d08db8934f2783a705f3604c3bb8"}, {"url": "http://172.17.1.17:8042", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "b320388c012a439fa1d6a248cd7911a5"}], "type": "alarming", "id": "2d7a8bfb6b32426183a8abbdc79feb0e", "name": "aodh"}, {"endpoints": [{"url": "http://172.17.1.17:8977", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "3fa1d2faa3e944e7b7eba3ec41c8e484"}, {"url": "http://10.0.0.110:8977", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "98ca598c3cd94a579352208c0daaa3f9"}, {"url": "http://172.17.1.17:8977", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "f576ad6ff81f430280d22dc81e0d42b7"}], "type": "event", "id": "46d1675dc5c4450993f74db6b40ee968", "name": "panko"}, {"endpoints": [{"url": "http://172.17.1.17:8776/v1/878c14e41152445d9065d7cdf87537b2", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "15e24c52de8742619da2c46c23183c89"}, {"url": "http://10.0.0.110:8776/v1/878c14e41152445d9065d7cdf87537b2", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "8146477dcff24ed48d3b4748a9e08540"}, {"url": "http://172.17.1.17:8776/v1/878c14e41152445d9065d7cdf87537b2", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "856cc042459141c29e7ae237fd453fb2"}], "type": "volume", "id": "5c11cf4858b140098d61841163e79086", "name": "cinder"}, {"endpoints": [{"url": "http://172.17.1.17:8776/v3/878c14e41152445d9065d7cdf87537b2", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "95cd26f695db4ab7a3820436ff86474f"}, {"url": "http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "be364aa3162f4ebf897a05e99374629d"}, {"url": "http://172.17.1.17:8776/v3/878c14e41152445d9065d7cdf87537b2", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "d48e6ba7f1f54bd38c6acc8e5099e949"}], "type": "volumev3", "id": "6fdb265642ea40ce88252a501ab0abc7", "name": "cinderv3"}, {"endpoints": [{"url": "http://172.17.1.17:9696", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "4eb73f7c7175492297012585964696d5"}, {"url": "http://172.17.1.17:9696", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "65bd0dc631f6424b8da5a4d43110d86f"}, {"url": "http://10.0.0.110:9696", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "801740b252004762afc4ee6b8cb75bd7"}], "type": "network", "id": "840fe70f226d47a9a4f3dba6005dcd43", "name": "neutron"}, {"endpoints": [{"url": "http://172.17.3.19:8080/v1/AUTH_878c14e41152445d9065d7cdf87537b2", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "6723763e72d7469093c246d0126fc243"}, {"url": "http://10.0.0.110:8080/v1/AUTH_878c14e41152445d9065d7cdf87537b2", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "87f0389765f049ec9f598221acb31cd1"}, {"url": "http://172.17.3.19:8080", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "fdd3abb4282d482daf3b82d8f0015f91"}], "type": "object-store", "id": "856d6ae5103f4ce0bfe964a7570df88d", "name": "swift"}, {"endpoints": [{"url": "http://10.0.0.110:8004/v1/878c14e41152445d9065d7cdf87537b2", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "9b6541ba83ee4cf0b4c8a70329c7b08a"}, {"url": "http://172.17.1.17:8004/v1/878c14e41152445d9065d7cdf87537b2", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "d188544071cf4b2e8cf49efd7001e216"}, {"url": "http://172.17.1.17:8004/v1/878c14e41152445d9065d7cdf87537b2", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "d733e120b27c46038d85d2131f899026"}], "type": "orchestration", "id": "8deaf564a4a74955831f0dfe74bad547", "name": "heat"}, {"endpoints": [], "type": "metering", "id": "a171cd5c7e4548c1b4eb7f2bfe500f4c", "name": "ceilometer"}, {"endpoints": [{"url": "http://172.17.1.17:5000", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "61d15aa2bed74c49a68b3de9d82edcb1"}, {"url": "http://10.0.0.110:5000", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "6f25ed9db3e341318469c4fa2e205cf5"}, {"url": "http://192.168.24.9:35357", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "a944188362434a399616c9ed72523da3"}], "type": "identity", "id": "aa6027205f0a4ce69f7fd0f9fef662ea", "name": "keystone"}, {"endpoints": [{"url": "http://172.17.1.17:8000/v1", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "3b93fc0240644a3a9ca34f3516e08033"}, {"url": "http://10.0.0.110:8000/v1", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "5db824840dbe446683ce6dd433ae5e02"}, {"url": "http://172.17.1.17:8000/v1", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "bc8dbb26fe374a73a87968eafb9d327e"}], "type": "cloudformation", "id": "b86eaa895410413889df25ce9945ba2e", "name": "heat-cfn"}, {"endpoints": [{"url": "http://172.17.1.17:8776/v2/878c14e41152445d9065d7cdf87537b2", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "409be1e8c34c4a8d914c1d59b1cc30c0"}, {"url": "http://172.17.1.17:8776/v2/878c14e41152445d9065d7cdf87537b2", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "6af4c5d1a9d64175a293c871b44eaf74"}, {"url": "http://10.0.0.110:8776/v2/878c14e41152445d9065d7cdf87537b2", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "fa222e4f3fba4ca890791bd4d2fb998d"}], "type": "volumev2", "id": "c2226f5335ae416fbceab6efc342c403", "name": "cinderv2"}, {"endpoints": [{"url": "http://172.17.1.17:8774/v2.1", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "1d0ad31dfe7e457ebbae5ba53adb0d9e"}, {"url": "http://10.0.0.110:8774/v2.1", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "3bf21f23a29f4c36878c031c24c2609c"}, {"url": "http://172.17.1.17:8774/v2.1", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "ea6eb938e8d941ab8b70c4866c4da7ae"}], "type": "compute", "id": "d349ad3948604031a7fe5224b514e1c9", "name": "nova"}, {"endpoints": [{"url": "http://172.17.1.17:8778/placement", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "164d852ac530450f8367b3e58d35cdf7"}, {"url": "http://10.0.0.110:8778/placement", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "1c05086348234aed941475d7caa82f7d"}, {"url": "http://172.17.1.17:8778/placement", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "5113b53a53ea4e429d28598a60f9795e"}], "type": "placement", "id": "e574ed0a05df45b792c646f2142da65f", "name": "placement"}, {"endpoints": [{"url": "http://10.0.0.110:8041", "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "08c06f4315f44a2783e88e2b471ff280"}, {"url": "http://172.17.1.17:8041", "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "1be47babe88f4610a2209a56675dc271"}, {"url": "http://172.17.1.17:8041", "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "b911ab7ffd984f438899925061a9843a"}], "type": "metric", "id": "fb33159d3c5149b1b7a6731b7938a300", "name": "gnocchi"}], "user": {"domain": {"id": "default", "name": "Default"}, "password_expires_at": null, "name": "admin", "id": "a9e6ef20e66b4541b9a63bb9fc20fd3f"}, "audit_ids": ["8OzK_MO_QOiZMMIiQFMjDA"], "issued_at": "2018-07-18T07:31:07.000000Z"}}
DEBUG:keystoneauth:REQ: curl -g -i -X GET http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914 -H "User-Agent: python-cinderclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}a91656e335060e387f6b0e18633c1986b3d8c661"
DEBUG:keystoneauth:RESP: [200] Date: Wed, 18 Jul 2018 07:31:07 GMT Server: Apache x-compute-request-id: req-e2025411-b029-4f89-9c0c-a5d6c71febb7 OpenStack-API-Version: volume 3.0 Vary: OpenStack-API-Version,Accept-Encoding x-openstack-request-id: req-e2025411-b029-4f89-9c0c-a5d6c71febb7 Content-Encoding: gzip Content-Length: 507 Content-Type: application/json 
RESP BODY: {"volume": {"migration_status": "success", "attachments": [], "links": [{"href": "http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914", "rel": "self"}, {"href": "http://10.0.0.110:8776/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914", "rel": "bookmark"}], "availability_zone": "dc2", "os-vol-host-attr:host": "controller-0@xtremio#xtremio", "encrypted": false, "updated_at": "2018-07-18T07:21:13.000000", "replication_status": null, "snapshot_id": null, "id": "7793ab23-2160-4f41-87fc-e7da8bd12914", "size": 1, "user_id": "a9e6ef20e66b4541b9a63bb9fc20fd3f", "os-vol-tenant-attr:tenant_id": "878c14e41152445d9065d7cdf87537b2", "os-vol-mig-status-attr:migstat": "success", "metadata": {}, "status": "available", "description": null, "multiattach": false, "source_volid": "ccd2b118-77eb-4934-bbe1-3eed7da942db", "consistencygroup_id": null, "os-vol-mig-status-attr:name_id": null, "name": null, "bootable": "false", "created_at": "2018-07-18T07:04:04.000000", "volume_type": "xtremio"}}

DEBUG:keystoneauth:GET call to volumev3 for http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914 used request id req-e2025411-b029-4f89-9c0c-a5d6c71febb7
DEBUG:keystoneauth:REQ: curl -g -i -X POST http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914/action -H "User-Agent: python-cinderclient" -H "Content-Type: application/json" -H "X-OpenStack-Request-ID: req-e2025411-b029-4f89-9c0c-a5d6c71febb7" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}a91656e335060e387f6b0e18633c1986b3d8c661" -d '{"os-retype": {"new_type": "lvm", "migration_policy": "on-demand"}}'
DEBUG:keystoneauth:RESP: [202] Date: Wed, 18 Jul 2018 07:31:07 GMT Server: Apache x-compute-request-id: req-9422b2c5-f1b0-4d1c-8447-fd70da2d63a5 OpenStack-API-Version: volume 3.0 Vary: OpenStack-API-Version x-openstack-request-id: req-9422b2c5-f1b0-4d1c-8447-fd70da2d63a5 Content-Length: 0 Content-Type: application/json
DEBUG:keystoneauth:POST call to volumev3 for http://10.0.0.110:8776/v3/878c14e41152445d9065d7cdf87537b2/volumes/7793ab23-2160-4f41-87fc-e7da8bd12914/action used request id req-9422b2c5-f1b0-4d1c-8447-fd70da2d63a5

This is not a bug, it's normal behavior.  The return value for the command means that the request parameters are correct, and therefore the request has been accepted for processing by the Cinder API.  Which have just passed it to the scheduler, which in turn passes it to the volume.

At the API layer we don't know if the retype needs to do a migration, so it cannot fail.

If a user issues what he thinks to be a valid command, he expects a valid return. Either the operation work as expected or he get an error message stating why his request is invalid/forbidden. 

Logic in this case might be normal behavior in doing nothing, which is fine I don't disagree on this fact. 

However returning no error means the user may assume the command completed without errors, while in reality it did nothing, which is misleading to say the lest. If an operation is invalid we must flag/inform the user of his abnormal request. To prove my point, see below two cases return an error. 

cinder delete 76630553-5cfe-4dcd-95d9-bd538cb8bb62  
Delete for volume 76630553-5cfe-4dcd-95d9-bd538cb8bb62 failed: No volume with a name or ID of '76630553-5cfe-4dcd-95d9-bd538cb8bb62' exists.                                                                                                 
ERROR: Unable to delete any of the specified volumes. if you delete a none exsiting volume id

Another example, deleting an attached volume. 
cinder delete b652c190-eb08-4682-9dac-b35bf3ce01c6
Delete for volume b652c190-eb08-4682-9dac-b35bf3ce01c6 failed: Invalid volume: Volume status must be available or error or error_restoring or error_extending or error_managing and must not be migrating, attached, belong to a group, have snapshots or be disassociated from snapshots after volume transfer. (HTTP 400) (Request-ID: req-7d0bbf8e-bd4f-4e98-8be2-18bb4f686a12)
ERROR: Unable to delete any of the specified volumes.

It's our prerogative our duty as QE to flag such cases.
Please reconsider this is a valid bug not to be brushed off. 
As per how to fix it might be impossible but it's still a bug.

Tzach, thank you for pressing the issue, as we clearly need to keep the user's
best interests in mind. In my view, however, this is not a situation where the
cinder API (and hence the CLI command) can avoid the problem.

Remember that openstack services provide a protocol endpoint which is served
by their XXX-api service (cinder-api for Cinder). The cinder-api code is
responsible for doing a fair amount of validation, but most requests then get
passed off to other Cinder services (c-vol, c-bak, c-sch) which are
responsible for doing the actual work.

Here, c-api has done as much validation as it can, and so from c-api's
perspective the request is considered valid. It returns HTTP 202 "Accepted" to
the client that made the request, which is why the CLI command doesn't display
an error. So far, everything looks good!

However, after the request is passed on to the other cinder-services, those
services do their own validation. Remember that Cinder backends are not
alike, and they have their own unique characteristics. In this instance, one
of the backends has determined it is unable to comply with a request that
seemed valid at the API level. This is why the operation eventually failed.

Much of this behavior is a result of the fact that most API requests are
asynchronous, meaning the entire operation does *not* run to completion before
sending any response back to the client. Think of what happens when you create
a volume. The c-api and c-sch services do a bunch of validation, and the CLI
command will indicate the volume request has been accepted. But, when you
check back later, the volume status might be "error" if c-vol encountered a
problem.

Hope this helps you understand our position on this.

We can try to address this by adding a --poll option to the client like we've done for volume creation, but that does fall more in the area of an enhancement.

The current model of how Cinder handles many asynchronous operation does leave a lot to be desired as far as usability, but this currently functioning as intended.

Opened upstream bug LP#1784870