← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1726779] [NEW] Attaching a volume to a VM generates authentication error

 

Public bug reported:

Description
===========
When I try to attach a volume to a VM, the operation fails. From the nova logs I can see first that an authentication fails and then an "Unexpected API Error".
This happens with the "nova volume-attach" command.

The "nova volume-attachments" command works correctly.

This happens regardless of the user I use, even with a user that has the
admin role.

Steps to reproduce
==================
$ nova --debug volume-attach cb22727f-32f8-49e9-8136-5395882d259a 2fe6c45f-cce9-43ea-90ac-ff0d574121b0

DEBUG (extension:180) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader')
DEBUG (extension:180) found extension EntryPoint.parse('token_endpoint = openstackclient.api.auth_plugin:TokenEndpoint')
DEBUG (extension:180) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1')
DEBUG (extension:180) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
DEBUG (extension:180) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
DEBUG (extension:180) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos')
DEBUG (extension:180) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials')
DEBUG (extension:180) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth')
DEBUG (extension:180) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP')
DEBUG (extension:180) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos')
DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-basic = gnocchiclient.auth:GnocchiBasicLoader')
DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-noauth = gnocchiclient.auth:GnocchiNoAuthLoader')
DEBUG (extension:180) found extension EntryPoint.parse('aodh-noauth = aodhclient.noauth:AodhNoAuthLoader')
DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:35357/v3 -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/2.18.0 python-requests/2.12.4 CPython/2.7.12"
DEBUG (connectionpool:212) Starting new HTTP connection (1): bfeb
DEBUG (connectionpool:400) http://bfeb:35357 "GET /v3 HTTP/1.1" 200 244
DEBUG (session:395) RESP: [200] Date: Tue, 24 Oct 2017 09:23:03 GMT Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-958c9ef8-5d5c-4e
2a-9270-8048a87aab73 Content-Length: 244 Keep-Alive: timeout=5, max=100 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"version": {"status": "stable", "updated": "2017-02-22T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id":
 "v3.8", "links": [{"href": "http://bfeb:35357/v3/";, "rel": "self"}]}}

DEBUG (session:640) GET call to None for http://bfeb:35357/v3 used request id req-958c9ef8-5d5c-4e2a-9270-8048a87aab73
DEBUG (base:165) Making authentication request to http://bfeb:35357/v3/auth/tokens
DEBUG (connectionpool:400) http://bfeb:35357 "POST /v3/auth/tokens HTTP/1.1" 201 6571
DEBUG (base:170) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "783bafe0d7f0424ab906dcba69674ce9", "name": "admin"}, {"id": "88289bfc880e4265b0851ace[95/1954]
, "name": "heat_stack_owner"}], "expires_at": "2017-10-24T10:23:03.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "2e51fec7c7f1408dbfe01b4eff8b6808", "name"
: "admin"}, "catalog": [{"endpoints": [{"url": "http://bfeb:9511/v1";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "0bc8662795d34f10a0ed48e633e3e004"}
, {"url": "http://bfeb:9511/v1";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "68f9b5aa26ab42b480d9420d3670be10"}, {"url": "http://bfeb:9511/v1";, "inter
face": "admin", "region": "regionOne", "region_id": "regionOne", "id": "f65872ee79a04c21912b097120e4d951"}], "type": "container-infra", "id": "35be9319ade845289e84dd5f6fc6d213", "name":
 "magnum"}, {"endpoints": [], "type": "metering", "id": "35f0b73e8d8d46c2b05691d474839942", "name": "ceilometer"}, {"endpoints": [{"url": "http://bfeb:8000/v1";, "interface": "internal",
 "region": "regionOne", "region_id": "regionOne", "id": "25d8725364d747fea091d68dcf3955fc"}, {"url": "http://bfeb:8000/v1";, "interface": "admin", "region": "regionOne", "region_id": "re
gionOne", "id": "355113aaf3c049d9b8432605b7acfa32"}, {"url": "http://bfeb:8000/v1";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "b686e52c06f843049c20f7
a56c3b5b65"}], "type": "cloudformation", "id": "37a94b9355f742a8bf17628e846d4052", "name": "heat-cfn"}, {"endpoints": [{"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "i
nterface": "public", "region": "regionOne", "region_id": "regionOne", "id": "7234c1e8ca6746b3ace25a63908e3f80"}, {"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "interfa
ce": "admin", "region": "regionOne", "region_id": "regionOne", "id": "a8eaae32976346ccbbc5b4bc4d0852c6"}, {"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "i
nternal", "region": "regionOne", "region_id": "regionOne", "id": "da3f790d07ab47d88a0337fc5f20c674"}], "type": "volumev2", "id": "43555323f8fb4e3097a52f0c7533c8dc", "name": "cinderv2"},
 {"endpoints": [{"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "527ddf17cf3448a0ad5525aed
0e23c85"}, {"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "a1205a8cc6894e47b0f9e4de088
7e12d"}, {"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "df8148a45c5d40fa91021e137e35b36
2"}], "type": "compute", "id": "5aabfb54877d4836970fd97119253f72", "name": "nova"}, {"endpoints": [{"url": "http://bfeb:8778";, "interface": "public", "region": "regionOne", "region_id":
 "regionOne", "id": "19b3ba83c8014d898b4ca261070ec2b2"}, {"url": "http://bfeb:8778";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "39591daf682b4dffb63
d859b1a57e9ad"}, {"url": "http://bfeb:8778";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "a84acda7878f4fd982ef3005e745a5bf"}], "type": "placement", "id"
: "5bcdb0ee6c3442c09d0cb74346b10742", "name": "placement"}, {"endpoints": [{"url": "http://bfeb:9292";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "0
018dc847c2e483a946ed235450dbb15"}, {"url": "http://bfeb:9292";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "05309355982d474ea85babf29b0d333d"}, {"url":
 "http://bfeb:9292";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "99bf7085ed63459e8f916fa9f0f64c6a"}], "type": "image", "id": "5d4a19325cf1433ab35a07d54
221c7fa", "name": "glance"}, {"endpoints": [{"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id":
 "456a6d8cbca24debb23dc609e94200be"}, {"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "797e8
aafadf84926afd3376c8a9749c7"}, {"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "9f7b13cb1
43744a3b9ecec139d00ecb4"}], "type": "orchestration", "id": "7217004a3c8347489d9ecbec62abce5f", "name": "heat"}, {"endpoints": [], "type": "volume", "id": "a6b020fea87f4dafaddf654791dcbf
20", "name": "cinder"}, {"endpoints": [{"url": "http://bfeb:9696";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "45e72197cbcc407abdd984be99fcee61"}, {
"url": "http://bfeb:9696";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "77b9f3044732428483390142e63d0c82"}, {"url": "http://bfeb:9696";, "interface": "pu
blic", "region": "regionOne", "region_id": "regionOne", "id": "98f758795c824dcda390bb74f255f005"}], "type": "network", "id": "d6f1333eeef6455d82ada7489b06350a", "name": "neutron"}, {"en
dpoints": [{"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "5a98242bb23248d2bf53fd31c7b5de59
"}, {"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "ad0dd8b63dd94aa480161f2c335e9ffa"},
{"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "ea1ef4fe045d4241a6411c124932ee39"}], "type
": "volumev3", "id": "e18f6330865c416cb7fe4fd02bcdf673", "name": "cinderv3"}, {"endpoints": [{"url": "http://bfeb:35357/v3/";, "interface": "internal", "region": "regionOne", "region_id"
: "regionOne", "id": "2d67010656f4472cb4ea2b24781b809b"}, {"url": "http://bfeb:5000/v3/";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "32e673ae819643c6
91deb931bc76ce50"}, {"url": "http://bfeb:35357/v3/";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "383c8fe6e5a641c59d9662d60ffd1494"}], "type": "identity
", "id": "e419c84ffee94673a7407eb1297e0581", "name": "keystone"}], "user": {"domain": {"id": "default", "name": "Default"}, "password_expires_at": null, "name": "admin", "id": "6468f6d8
2c734776923e367990e8a5f1"}, "audit_ids": ["yuBrTF4PTva_ig_RN_m-ZA"], "issued_at": "2017-10-24T09:23:03.000000Z"}}
REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96f
f3c5d9f17e62207bd72292"
DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA
1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
DEBUG (connectionpool:212) Starting new HTTP connection (1): bfeb
DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 HTTP/1.1" 404 112
RESP: [404] Content-Length: 112 Content-Type: application/json; charset=UTF-8 X-Compute-Request-Id: req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 Date: Tue, 24 Oct 2017 09:23:03 GMT Connecti
on: keep-alive
RESP BODY: {"message": "The resource could not be found.<br /><br />\n\n\n", "code": "404 Not Found", "title": "Not Found"}

DEBUG (session:395) RESP: [404] Content-Length: 112 Content-Type: application/json; charset=UTF-8 X-Compute-Request-Id: req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 Date: Tue, 24 Oct 2017 0
9:23:03 GMT Connection: keep-alive
RESP BODY: {"message": "The resource could not be found.<br /><br />\n\n\n", "code": "404 Not Found", "title": "Not Found"}

GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 used request id req-4b96f757-a50a-4fd6-b7d3-00b9127297c5                                         [45/1954]
DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 used request id req-4b96f757-a50a-4fd6-b7d3-00b9127297c5
REQ: curl -g -i -X GET http://bfeb:8774/v2.1/ -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/ -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62
207bd72292"
DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/ HTTP/1.1" 200 378
RESP: [200] Content-Length: 378 Content-Type: application/json Openstack-Api-Version: compute 2.1 X-Openstack-Nova-Api-Version: 2.1 Vary: OpenStack-API-Version, X-OpenStack-Nova-API-Ver
sion X-Compute-Request-Id: req-66b3c7a4-0f07-4692-9172-04587445278d Date: Tue, 24 Oct 2017 09:23:03 GMT Connection: keep-alive
RESP BODY: {"version": {"status": "CURRENT", "updated": "2013-07-23T11:33:21Z", "links": [{"href": "http://bfeb:8774/v2.1/";, "rel": "self"}, {"href": "http://docs.openstack.org/";, "type
": "text/html", "rel": "describedby"}], "min_version": "2.1", "version": "2.42", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1
"}], "id": "v2.1"}}

DEBUG (session:395) RESP: [200] Content-Length: 378 Content-Type: application/json Openstack-Api-Version: compute 2.1 X-Openstack-Nova-Api-Version: 2.1 Vary: OpenStack-API-Version, X-Op
enStack-Nova-API-Version X-Compute-Request-Id: req-66b3c7a4-0f07-4692-9172-04587445278d Date: Tue, 24 Oct 2017 09:23:03 GMT Connection: keep-alive
RESP BODY: {"version": {"status": "CURRENT", "updated": "2013-07-23T11:33:21Z", "links": [{"href": "http://bfeb:8774/v2.1/";, "rel": "self"}, {"href": "http://docs.openstack.org/";, "type
": "text/html", "rel": "describedby"}], "min_version": "2.1", "version": "2.42", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1
"}], "id": "v2.1"}}

GET call to compute for http://bfeb:8774/v2.1/ used request id req-66b3c7a4-0f07-4692-9172-04587445278d
DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/ used request id req-66b3c7a4-0f07-4692-9172-04587445278d
DEBUG (extension:180) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader')
DEBUG (extension:180) found extension EntryPoint.parse('token_endpoint = openstackclient.api.auth_plugin:TokenEndpoint')
DEBUG (extension:180) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1')
DEBUG (extension:180) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
DEBUG (extension:180) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
DEBUG (extension:180) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos')
DEBUG (extension:180) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials')
DEBUG (extension:180) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth')
DEBUG (extension:180) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
DEBUG (extension:180) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP')
DEBUG (extension:180) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
DEBUG (extension:180) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos')
DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-basic = gnocchiclient.auth:GnocchiBasicLoader')
DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-noauth = gnocchiclient.auth:GnocchiNoAuthLoader')
DEBUG (extension:180) found extension EntryPoint.parse('aodh-noauth = aodhclient.noauth:AodhNoAuthLoader')
/usr/lib/python2.7/dist-packages/novaclient/client.py:278: UserWarning: The 'tenant_id' argument is deprecated in Ocata and its use may result in errors in future releases. As 'project_
id' is provided, the 'tenant_id' argument will be ignored.
  warnings.warn(msg)
DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a -H "OpenStack-API-Version: compute 2.41" -
H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-OpenStack-Nova-API-Version: 2.41" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a HTTP/1.1" 200 1931
DEBUG (session:395) RESP: [200] Content-Length: 1931 Content-Type: application/json Openstack-Api-Version: compute 2.41 X-Openstack-Nova-Api-Version: 2.41 Vary: OpenStack-API-Version, X
-OpenStack-Nova-API-Version X-Compute-Request-Id: req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 Date: Tue, 24 Oct 2017 09:23:04 GMT Connection: keep-alive
RESP BODY: {"server": {"OS-EXT-STS:task_state": null, "addresses": {"flat": [{"OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:9b:7e:20", "version": 4, "addr": "192.168.45.35", "OS-EXT-IPS:type": "
fixed"}]}, "links": [{"href": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a";, "rel": "self"}, {"href": "http://bfeb:8774/2e51fec7c
7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a", "rel": "bookmark"}], "image": {"id": "a7b259f6-7c62-4a5e-861c-81f96a5d3fb7", "links": [{"href": "http://bfeb:8774/
2e51fec7c7f1408dbfe01b4eff8b6808/images/a7b259f6-7c62-4a5e-861c-81f96a5d3fb7", "rel": "bookmark"}]}, "OS-EXT-SRV-ATTR:user_data": null, "OS-EXT-STS:vm_state": "active", "OS-EXT-SRV-ATTR
:instance_name": "instance-0000112f", "OS-EXT-SRV-ATTR:root_device_name": "/dev/vda", "OS-SRV-USG:launched_at": "2017-10-19T07:17:23.000000", "flavor": {"id": "2", "links": [{"href": "h
ttp://bfeb:8774/2e51fec7c7f1408dbfe01b4eff8b6808/flavors/2", "rel": "bookmark"}]}, "id": "cb22727f-32f8-49e9-8136-5395882d259a", "OS-SRV-USG:terminated_at": null, "os-extended-volumes:v
olumes_attached": [], "user_id": "fee810060f3c48918ec95767200c788b", "OS-EXT-SRV-ATTR:hostname": "zoe", "OS-DCF:diskConfig": "AUTO", "accessIPv4": "", "accessIPv6": "", "OS-EXT-SRV-ATTR
:reservation_id": "r-t1nd7157", "progress": 0, "OS-EXT-STS:power_state": 1, "OS-EXT-AZ:availability_zone": "pool", "metadata": {}, "status": "ACTIVE", "OS-EXT-SRV-ATTR:ramdisk_id": "",
"updated": "2017-10-19T07:17:23Z", "hostId": "65bf65f5a41cbf02044f741fabe281325d698472a22e370df5b0c564", "OS-EXT-SRV-ATTR:host": "bf2", "description": "zoe", "tags": [], "key_name": "Cl
oud", "OS-EXT-SRV-ATTR:kernel_id": "", "locked": false, "OS-EXT-SRV-ATTR:hypervisor_hostname": "bf2", "name": "zoe", "OS-EXT-SRV-ATTR:launch_index": 0, "created": "2017-10-19T07:15:36Z"
, "tenant_id": "aa72257f79f44ab5a73da2bee096217c", "host_status": "UP", "config_drive": ""}}

DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a used request id req-0ad9eddf-78c5-404f-91
d8-fa412fe1ab85
DEBUG (session:347) REQ: curl -g -i -X POST http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments -H "Accept: applica
tion/json" -H "User-Agent: python-novaclient" -H "OpenStack-API-Version: compute 2.41" -H "X-OpenStack-Nova-API-Version: 2.41" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207b
d72292" -H "Content-Type: application/json" -d '{"volumeAttachment": {"volumeId": "2fe6c45f-cce9-43ea-90ac-ff0d574121b0"}}'
DEBUG (connectionpool:400) http://bfeb:8774 "POST /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments HTTP/1.1" 500 210
DEBUG (session:395) RESP: [500] Openstack-Api-Version: compute 2.41 X-Openstack-Nova-Api-Version: 2.41 Vary: OpenStack-API-Version, X-OpenStack-Nova-API-Version Content-Type: applicatio
n/json; charset=UTF-8 Content-Length: 210 X-Compute-Request-Id: req-7e934a71-2236-4afa-8d38-6092d11d37fe Date: Tue, 24 Oct 2017 09:23:05 GMT Connection: keep-alive
RESP BODY: {"computeFault": {"message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'cinderclient.excep
tions.Unauthorized'>", "code": 500}}

DEBUG (session:640) POST call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments used request id re
q-7e934a71-2236-4afa-8d38-6092d11d37fe
DEBUG (shell:959) Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 957, in main
    OpenStackComputeShell().main(argv)
  File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 879, in main
    args.func(self.cs, args)
  File "/usr/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 2513, in do_volume_attach
    args.device)
  File "/usr/lib/python2.7/dist-packages/novaclient/v2/volumes.py", line 53, in create_server_volume
    body, "volumeAttachment")
  File "/usr/lib/python2.7/dist-packages/novaclient/base.py", line 361, in _create
    resp, body = self.api.client.post(url, body=body)
  File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 223, in post
    return self.request(url, 'POST', **kwargs)
  File "/usr/lib/python2.7/dist-packages/novaclient/client.py", line 80, in request
    raise exceptions.from_response(resp, body, url, method)
ClientException: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)


Expected result
===============
The volume is attached to the VM.

Actual result
=============
Cryptic errors are generated.

Environment
===========
1. Exact version of OpenStack you are running. See the following
  list for all releases: http://docs.openstack.org/releases/

# dpkg -l |grep nova
ii  nova-api                             2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - API frontend
ii  nova-common                          2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - common files
ii  nova-conductor                       2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - conductor service
ii  nova-consoleauth                     2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - Console Authenticator
ii  nova-novncproxy                      2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - NoVNC proxy
ii  nova-placement-api                   2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - placement API frontend
ii  nova-scheduler                       2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - virtual machine scheduler
ii  python-nova                          2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute Python libraries
ii  python-novaclient                    2:7.1.0-0ubuntu1~cloud0                    all          client library for OpenStack Compute API - Python 2.7

2. Which hypervisor did you use?
Libvirt + KVM

2. Which storage type did you use?
Ceph

3. Which networking type did you use?
Neutron flat network

Logs & Configs
==============
Relevant part of the nova-api.log

2017-10-24 11:23:03.320 18537 DEBUG nova.osapi_compute.wsgi.server [req-ba39611c-6ea1-4abf-ae25-786dd1f42082 - - - - -] (18537) accepted ('192.168.46.26', 36478) server /usr/lib/python2
.7/dist-packages/eventlet/wsgi.py:867
2017-10-24 11:23:03.377 18537 INFO nova.osapi_compute.wsgi.server [req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default d
efault] 192.168.46.26 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 HTTP/1.1" status: 404 len: 331 time: 0.0551920
2017-10-24 11:23:03.391 18537 DEBUG nova.api.openstack.wsgi [req-66b3c7a4-0f07-4692-9172-04587445278d 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default
] Calling method '<bound method VersionsController.show of <nova.api.openstack.compute.versionsV21.VersionsController object at 0x7ff888997a50>>' _process_stack /usr/lib/python2.7/dist-
packages/nova/api/openstack/wsgi.py:626
2017-10-24 11:23:03.393 18537 INFO nova.osapi_compute.wsgi.server [req-66b3c7a4-0f07-4692-9172-04587445278d 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default d
efault] 192.168.46.26 "GET /v2.1/ HTTP/1.1" status: 200 len: 711 time: 0.0120900
2017-10-24 11:23:03.606 18537 DEBUG nova.api.openstack.wsgi [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default
] Calling method '<bound method ServersController.show of <nova.api.openstack.compute.servers.ServersController object at 0x7ff888a4bfd0>>' _process_stack /usr/lib/python2.7/dist-packag
es/nova/api/openstack/wsgi.py:626
2017-10-24 11:23:03.614 18537 DEBUG nova.compute.api [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] [inst
ance: cb22727f-32f8-49e9-8136-5395882d259a] Fetching instance by UUID get /usr/lib/python2.7/dist-packages/nova/compute/api.py:2360
2017-10-24 11:23:03.640 18537 DEBUG oslo_db.sqlalchemy.engines [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default defa
ult] 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 _check
_effective_sql_mode /usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:261
2017-10-24 11:23:03.654 18537 DEBUG oslo_concurrency.lockutils [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default defa
ult] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:273
2017-10-24 11:23:03.655 18537 DEBUG oslo_concurrency.lockutils [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:285
2017-10-24 11:23:03.668 18537 DEBUG oslo_db.sqlalchemy.engines [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 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 _check_effective_sql_mode /usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:261
2017-10-24 11:23:03.790 18537 DEBUG nova.objects.instance [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lazy-loading 'services' on Instance uuid cb22727f-32f8-49e9-8136-5395882d259a obj_load_attr /usr/lib/python2.7/dist-packages/nova/objects/instance.py:1034
2017-10-24 11:23:04.594 18537 DEBUG neutronclient.v2_0.client [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] GET call to neutron for http://bfeb:9696/v2.0/ports.json?device_id=cb22727f-32f8-49e9-8136-5395882d259a used request id req-8aaaa9ad-f1ba-43ac-b9dc-bb97a050a1d1 _append_request_id /usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2017-10-24 11:23:04.620 18537 DEBUG nova.policy [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'6468f6d82c734776923e367990e8a5f1', 'roles': [u'admin', u'heat_stack_owner'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'2e51fec7c7f1408dbfe01b4eff8b6808', 'project_domain_id': u'default'} authorize /usr/lib/python2.7/dist-packages/nova/policy.py:168
2017-10-24 11:23:04.695 18537 INFO nova.osapi_compute.wsgi.server [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 192.168.46.26 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a HTTP/1.1" status: 200 len: 2267 time: 1.1006789
2017-10-24 11:23:04.725 18537 DEBUG nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Action: 'create', calling method: <bound method VolumeAttachmentController.create of <nova.api.openstack.compute.volumes.VolumeAttachmentController object at 0x7ff88884a090>>, body: {"volumeAttachment": {"volumeId": "2fe6c45f-cce9-43ea-90ac-ff0d574121b0"}} _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:623
2017-10-24 11:23:04.741 18537 DEBUG nova.compute.api [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] [instance: cb22727f-32f8-49e9-8136-5395882d259a] Fetching instance by UUID get /usr/lib/python2.7/dist-packages/nova/compute/api.py:2360
2017-10-24 11:23:04.760 18537 DEBUG oslo_concurrency.lockutils [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:273
2017-10-24 11:23:04.761 18537 DEBUG oslo_concurrency.lockutils [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:285
2017-10-24 11:23:04.908 18537 DEBUG oslo_messaging._drivers.amqpdriver [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] CALL msg_id: 259736aee2ca45569a84b1b1acced5f3 exchange 'nova' topic 'compute.bf2' _send /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:442
2017-10-24 11:23:05.043 18537 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 259736aee2ca45569a84b1b1acced5f3 __call__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:299
2017-10-24 11:23:05.061 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] REQ: curl -g -i -X GET http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808/volumes/2fe6c45f-cce9-43ea-90ac-ff0d574121b0 -H "X-Service-Token: {SHA1}00e767c36ea5c08c4f5e4dbdbbe788da449a1990" -H "User-Agent: python-cinderclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:347
2017-10-24 11:23:05.069 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] RESP: [401] Date: Tue, 24 Oct 2017 09:23:05 GMT Server: Apache/2.4.18 (Ubuntu) x-openstack-request-id: req-f8ce808c-bcae-4729-a48d-2ebd997fd521 WWW-Authenticate: Keystone uri='http://bfeb:5000' Content-Length: 114 Keep-Alive: timeout=5, max=100 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-10-24 11:23:05.069 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] GET call to cinderv2 for http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808/volumes/2fe6c45f-cce9-43ea-90ac-ff0d574121b0 used request id req-f8ce808c-bcae-4729-a48d-2ebd997fd521 request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:640
2017-10-24 11:23:05.075 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] RESP: [401] Date: Tue, 24 Oct 2017 09:23:05 GMT Server: Apache/2.4.18 (Ubuntu) x-openstack-request-id: req-993ee979-8659-4afd-9db5-e858808d432a WWW-Authenticate: Keystone uri='http://bfeb:5000' Content-Length: 114 Keep-Alive: timeout=5, max=99 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Unexpected exception in API method
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 338, in wrapped
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 108, in wrapper
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/volumes.py", line 326, in create
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume_id, device)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 170, in inner
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return function(self, context, instance, *args, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 151, in inner
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return f(self, context, instance, *args, **kw)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3701, in attach_volume
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     disk_bus, device_type)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3644, in _attach_volume
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume_bdm.destroy()
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     self.force_reraise()
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3640, in _attach_volume
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     self._check_attach_and_reserve_volume(context, volume_id, instance)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3624, in _check_attach_and_reserve_volume
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume = self.volume_api.get(context, volume_id)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 168, in wrapper
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     res = method(self, ctx, *args, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 190, in wrapper
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     res = method(self, ctx, volume_id, *args, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 234, in get
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     item = cinderclient(context).volumes.get(volume_id)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/v2/volumes.py", line 277, in get
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self._get("/volumes/%s" % volume_id, "volume")
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/base.py", line 313, in _get
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     resp, body = self.api.client.get(url)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 164, in get
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self._cs_request(url, 'GET', **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 155, in _cs_request
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self.request(url, method, **kwargs)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 144, in request
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     raise exceptions.from_response(resp, body)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions Unauthorized: The request you have made requires authentication. (HTTP 401)
2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions
2017-10-24 11:23:05.088 18537 INFO nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'>
2017-10-24 11:23:05.089 18537 DEBUG nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'cinderclient.exceptions.Unauthorized'> __call__ /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:1039
2017-10-24 11:23:05.091 18537 INFO nova.osapi_compute.wsgi.server [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 192.168.46.26 "POST /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments HTTP/1.1" status: 500 len: 579 time: 0.3905520

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1726779

Title:
  Attaching a volume to a VM generates authentication error

Status in OpenStack Compute (nova):
  New

Bug description:
  Description
  ===========
  When I try to attach a volume to a VM, the operation fails. From the nova logs I can see first that an authentication fails and then an "Unexpected API Error".
  This happens with the "nova volume-attach" command.

  The "nova volume-attachments" command works correctly.

  This happens regardless of the user I use, even with a user that has
  the admin role.

  Steps to reproduce
  ==================
  $ nova --debug volume-attach cb22727f-32f8-49e9-8136-5395882d259a 2fe6c45f-cce9-43ea-90ac-ff0d574121b0

  DEBUG (extension:180) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('token_endpoint = openstackclient.api.auth_plugin:TokenEndpoint')
  DEBUG (extension:180) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1')
  DEBUG (extension:180) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
  DEBUG (extension:180) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
  DEBUG (extension:180) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos')
  DEBUG (extension:180) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials')
  DEBUG (extension:180) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth')
  DEBUG (extension:180) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP')
  DEBUG (extension:180) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos')
  DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-basic = gnocchiclient.auth:GnocchiBasicLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-noauth = gnocchiclient.auth:GnocchiNoAuthLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('aodh-noauth = aodhclient.noauth:AodhNoAuthLoader')
  DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:35357/v3 -H "Accept: application/json" -H "User-Agent: nova keystoneauth1/2.18.0 python-requests/2.12.4 CPython/2.7.12"
  DEBUG (connectionpool:212) Starting new HTTP connection (1): bfeb
  DEBUG (connectionpool:400) http://bfeb:35357 "GET /v3 HTTP/1.1" 200 244
  DEBUG (session:395) RESP: [200] Date: Tue, 24 Oct 2017 09:23:03 GMT Server: Apache/2.4.18 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-958c9ef8-5d5c-4e
  2a-9270-8048a87aab73 Content-Length: 244 Keep-Alive: timeout=5, max=100 Connection: Keep-Alive Content-Type: application/json
  RESP BODY: {"version": {"status": "stable", "updated": "2017-02-22T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id":
   "v3.8", "links": [{"href": "http://bfeb:35357/v3/";, "rel": "self"}]}}

  DEBUG (session:640) GET call to None for http://bfeb:35357/v3 used request id req-958c9ef8-5d5c-4e2a-9270-8048a87aab73
  DEBUG (base:165) Making authentication request to http://bfeb:35357/v3/auth/tokens
  DEBUG (connectionpool:400) http://bfeb:35357 "POST /v3/auth/tokens HTTP/1.1" 201 6571
  DEBUG (base:170) {"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "783bafe0d7f0424ab906dcba69674ce9", "name": "admin"}, {"id": "88289bfc880e4265b0851ace[95/1954]
  , "name": "heat_stack_owner"}], "expires_at": "2017-10-24T10:23:03.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "2e51fec7c7f1408dbfe01b4eff8b6808", "name"
  : "admin"}, "catalog": [{"endpoints": [{"url": "http://bfeb:9511/v1";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "0bc8662795d34f10a0ed48e633e3e004"}
  , {"url": "http://bfeb:9511/v1";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "68f9b5aa26ab42b480d9420d3670be10"}, {"url": "http://bfeb:9511/v1";, "inter
  face": "admin", "region": "regionOne", "region_id": "regionOne", "id": "f65872ee79a04c21912b097120e4d951"}], "type": "container-infra", "id": "35be9319ade845289e84dd5f6fc6d213", "name":
   "magnum"}, {"endpoints": [], "type": "metering", "id": "35f0b73e8d8d46c2b05691d474839942", "name": "ceilometer"}, {"endpoints": [{"url": "http://bfeb:8000/v1";, "interface": "internal",
   "region": "regionOne", "region_id": "regionOne", "id": "25d8725364d747fea091d68dcf3955fc"}, {"url": "http://bfeb:8000/v1";, "interface": "admin", "region": "regionOne", "region_id": "re
  gionOne", "id": "355113aaf3c049d9b8432605b7acfa32"}, {"url": "http://bfeb:8000/v1";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "b686e52c06f843049c20f7
  a56c3b5b65"}], "type": "cloudformation", "id": "37a94b9355f742a8bf17628e846d4052", "name": "heat-cfn"}, {"endpoints": [{"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "i
  nterface": "public", "region": "regionOne", "region_id": "regionOne", "id": "7234c1e8ca6746b3ace25a63908e3f80"}, {"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "interfa
  ce": "admin", "region": "regionOne", "region_id": "regionOne", "id": "a8eaae32976346ccbbc5b4bc4d0852c6"}, {"url": "http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "i
  nternal", "region": "regionOne", "region_id": "regionOne", "id": "da3f790d07ab47d88a0337fc5f20c674"}], "type": "volumev2", "id": "43555323f8fb4e3097a52f0c7533c8dc", "name": "cinderv2"},
   {"endpoints": [{"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "527ddf17cf3448a0ad5525aed
  0e23c85"}, {"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "a1205a8cc6894e47b0f9e4de088
  7e12d"}, {"url": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "df8148a45c5d40fa91021e137e35b36
  2"}], "type": "compute", "id": "5aabfb54877d4836970fd97119253f72", "name": "nova"}, {"endpoints": [{"url": "http://bfeb:8778";, "interface": "public", "region": "regionOne", "region_id":
   "regionOne", "id": "19b3ba83c8014d898b4ca261070ec2b2"}, {"url": "http://bfeb:8778";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "39591daf682b4dffb63
  d859b1a57e9ad"}, {"url": "http://bfeb:8778";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "a84acda7878f4fd982ef3005e745a5bf"}], "type": "placement", "id"
  : "5bcdb0ee6c3442c09d0cb74346b10742", "name": "placement"}, {"endpoints": [{"url": "http://bfeb:9292";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "0
  018dc847c2e483a946ed235450dbb15"}, {"url": "http://bfeb:9292";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "05309355982d474ea85babf29b0d333d"}, {"url":
   "http://bfeb:9292";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "99bf7085ed63459e8f916fa9f0f64c6a"}], "type": "image", "id": "5d4a19325cf1433ab35a07d54
  221c7fa", "name": "glance"}, {"endpoints": [{"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id":
   "456a6d8cbca24debb23dc609e94200be"}, {"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "797e8
  aafadf84926afd3376c8a9749c7"}, {"url": "http://bfeb:8004/v1/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "9f7b13cb1
  43744a3b9ecec139d00ecb4"}], "type": "orchestration", "id": "7217004a3c8347489d9ecbec62abce5f", "name": "heat"}, {"endpoints": [], "type": "volume", "id": "a6b020fea87f4dafaddf654791dcbf
  20", "name": "cinder"}, {"endpoints": [{"url": "http://bfeb:9696";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "45e72197cbcc407abdd984be99fcee61"}, {
  "url": "http://bfeb:9696";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "77b9f3044732428483390142e63d0c82"}, {"url": "http://bfeb:9696";, "interface": "pu
  blic", "region": "regionOne", "region_id": "regionOne", "id": "98f758795c824dcda390bb74f255f005"}], "type": "network", "id": "d6f1333eeef6455d82ada7489b06350a", "name": "neutron"}, {"en
  dpoints": [{"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "5a98242bb23248d2bf53fd31c7b5de59
  "}, {"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "internal", "region": "regionOne", "region_id": "regionOne", "id": "ad0dd8b63dd94aa480161f2c335e9ffa"},
  {"url": "http://bfeb:8776/v3/2e51fec7c7f1408dbfe01b4eff8b6808";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "ea1ef4fe045d4241a6411c124932ee39"}], "type
  ": "volumev3", "id": "e18f6330865c416cb7fe4fd02bcdf673", "name": "cinderv3"}, {"endpoints": [{"url": "http://bfeb:35357/v3/";, "interface": "internal", "region": "regionOne", "region_id"
  : "regionOne", "id": "2d67010656f4472cb4ea2b24781b809b"}, {"url": "http://bfeb:5000/v3/";, "interface": "public", "region": "regionOne", "region_id": "regionOne", "id": "32e673ae819643c6
  91deb931bc76ce50"}, {"url": "http://bfeb:35357/v3/";, "interface": "admin", "region": "regionOne", "region_id": "regionOne", "id": "383c8fe6e5a641c59d9662d60ffd1494"}], "type": "identity
  ", "id": "e419c84ffee94673a7407eb1297e0581", "name": "keystone"}], "user": {"domain": {"id": "default", "name": "Default"}, "password_expires_at": null, "name": "admin", "id": "6468f6d8
  2c734776923e367990e8a5f1"}, "audit_ids": ["yuBrTF4PTva_ig_RN_m-ZA"], "issued_at": "2017-10-24T09:23:03.000000Z"}}
  REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96f
  f3c5d9f17e62207bd72292"
  DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA
  1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
  DEBUG (connectionpool:212) Starting new HTTP connection (1): bfeb
  DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 HTTP/1.1" 404 112
  RESP: [404] Content-Length: 112 Content-Type: application/json; charset=UTF-8 X-Compute-Request-Id: req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 Date: Tue, 24 Oct 2017 09:23:03 GMT Connecti
  on: keep-alive
  RESP BODY: {"message": "The resource could not be found.<br /><br />\n\n\n", "code": "404 Not Found", "title": "Not Found"}

  DEBUG (session:395) RESP: [404] Content-Length: 112 Content-Type: application/json; charset=UTF-8 X-Compute-Request-Id: req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 Date: Tue, 24 Oct 2017 0
  9:23:03 GMT Connection: keep-alive
  RESP BODY: {"message": "The resource could not be found.<br /><br />\n\n\n", "code": "404 Not Found", "title": "Not Found"}

  GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 used request id req-4b96f757-a50a-4fd6-b7d3-00b9127297c5                                         [45/1954]
  DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 used request id req-4b96f757-a50a-4fd6-b7d3-00b9127297c5
  REQ: curl -g -i -X GET http://bfeb:8774/v2.1/ -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
  DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/ -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62
  207bd72292"
  DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/ HTTP/1.1" 200 378
  RESP: [200] Content-Length: 378 Content-Type: application/json Openstack-Api-Version: compute 2.1 X-Openstack-Nova-Api-Version: 2.1 Vary: OpenStack-API-Version, X-OpenStack-Nova-API-Ver
  sion X-Compute-Request-Id: req-66b3c7a4-0f07-4692-9172-04587445278d Date: Tue, 24 Oct 2017 09:23:03 GMT Connection: keep-alive
  RESP BODY: {"version": {"status": "CURRENT", "updated": "2013-07-23T11:33:21Z", "links": [{"href": "http://bfeb:8774/v2.1/";, "rel": "self"}, {"href": "http://docs.openstack.org/";, "type
  ": "text/html", "rel": "describedby"}], "min_version": "2.1", "version": "2.42", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1
  "}], "id": "v2.1"}}

  DEBUG (session:395) RESP: [200] Content-Length: 378 Content-Type: application/json Openstack-Api-Version: compute 2.1 X-Openstack-Nova-Api-Version: 2.1 Vary: OpenStack-API-Version, X-Op
  enStack-Nova-API-Version X-Compute-Request-Id: req-66b3c7a4-0f07-4692-9172-04587445278d Date: Tue, 24 Oct 2017 09:23:03 GMT Connection: keep-alive
  RESP BODY: {"version": {"status": "CURRENT", "updated": "2013-07-23T11:33:21Z", "links": [{"href": "http://bfeb:8774/v2.1/";, "rel": "self"}, {"href": "http://docs.openstack.org/";, "type
  ": "text/html", "rel": "describedby"}], "min_version": "2.1", "version": "2.42", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1
  "}], "id": "v2.1"}}

  GET call to compute for http://bfeb:8774/v2.1/ used request id req-66b3c7a4-0f07-4692-9172-04587445278d
  DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/ used request id req-66b3c7a4-0f07-4692-9172-04587445278d
  DEBUG (extension:180) found extension EntryPoint.parse('v1password = swiftclient.authv1:PasswordLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('token_endpoint = openstackclient.api.auth_plugin:TokenEndpoint')
  DEBUG (extension:180) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1')
  DEBUG (extension:180) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
  DEBUG (extension:180) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
  DEBUG (extension:180) found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos')
  DEBUG (extension:180) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials')
  DEBUG (extension:180) found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth')
  DEBUG (extension:180) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
  DEBUG (extension:180) found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP')
  DEBUG (extension:180) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
  DEBUG (extension:180) found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos')
  DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-basic = gnocchiclient.auth:GnocchiBasicLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('gnocchi-noauth = gnocchiclient.auth:GnocchiNoAuthLoader')
  DEBUG (extension:180) found extension EntryPoint.parse('aodh-noauth = aodhclient.noauth:AodhNoAuthLoader')
  /usr/lib/python2.7/dist-packages/novaclient/client.py:278: UserWarning: The 'tenant_id' argument is deprecated in Ocata and its use may result in errors in future releases. As 'project_
  id' is provided, the 'tenant_id' argument will be ignored.
    warnings.warn(msg)
  DEBUG (session:347) REQ: curl -g -i -X GET http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a -H "OpenStack-API-Version: compute 2.41" -
  H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-OpenStack-Nova-API-Version: 2.41" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292"
  DEBUG (connectionpool:400) http://bfeb:8774 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a HTTP/1.1" 200 1931
  DEBUG (session:395) RESP: [200] Content-Length: 1931 Content-Type: application/json Openstack-Api-Version: compute 2.41 X-Openstack-Nova-Api-Version: 2.41 Vary: OpenStack-API-Version, X
  -OpenStack-Nova-API-Version X-Compute-Request-Id: req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 Date: Tue, 24 Oct 2017 09:23:04 GMT Connection: keep-alive
  RESP BODY: {"server": {"OS-EXT-STS:task_state": null, "addresses": {"flat": [{"OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:9b:7e:20", "version": 4, "addr": "192.168.45.35", "OS-EXT-IPS:type": "
  fixed"}]}, "links": [{"href": "http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a";, "rel": "self"}, {"href": "http://bfeb:8774/2e51fec7c
  7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a", "rel": "bookmark"}], "image": {"id": "a7b259f6-7c62-4a5e-861c-81f96a5d3fb7", "links": [{"href": "http://bfeb:8774/
  2e51fec7c7f1408dbfe01b4eff8b6808/images/a7b259f6-7c62-4a5e-861c-81f96a5d3fb7", "rel": "bookmark"}]}, "OS-EXT-SRV-ATTR:user_data": null, "OS-EXT-STS:vm_state": "active", "OS-EXT-SRV-ATTR
  :instance_name": "instance-0000112f", "OS-EXT-SRV-ATTR:root_device_name": "/dev/vda", "OS-SRV-USG:launched_at": "2017-10-19T07:17:23.000000", "flavor": {"id": "2", "links": [{"href": "h
  ttp://bfeb:8774/2e51fec7c7f1408dbfe01b4eff8b6808/flavors/2", "rel": "bookmark"}]}, "id": "cb22727f-32f8-49e9-8136-5395882d259a", "OS-SRV-USG:terminated_at": null, "os-extended-volumes:v
  olumes_attached": [], "user_id": "fee810060f3c48918ec95767200c788b", "OS-EXT-SRV-ATTR:hostname": "zoe", "OS-DCF:diskConfig": "AUTO", "accessIPv4": "", "accessIPv6": "", "OS-EXT-SRV-ATTR
  :reservation_id": "r-t1nd7157", "progress": 0, "OS-EXT-STS:power_state": 1, "OS-EXT-AZ:availability_zone": "pool", "metadata": {}, "status": "ACTIVE", "OS-EXT-SRV-ATTR:ramdisk_id": "",
  "updated": "2017-10-19T07:17:23Z", "hostId": "65bf65f5a41cbf02044f741fabe281325d698472a22e370df5b0c564", "OS-EXT-SRV-ATTR:host": "bf2", "description": "zoe", "tags": [], "key_name": "Cl
  oud", "OS-EXT-SRV-ATTR:kernel_id": "", "locked": false, "OS-EXT-SRV-ATTR:hypervisor_hostname": "bf2", "name": "zoe", "OS-EXT-SRV-ATTR:launch_index": 0, "created": "2017-10-19T07:15:36Z"
  , "tenant_id": "aa72257f79f44ab5a73da2bee096217c", "host_status": "UP", "config_drive": ""}}

  DEBUG (session:640) GET call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a used request id req-0ad9eddf-78c5-404f-91
  d8-fa412fe1ab85
  DEBUG (session:347) REQ: curl -g -i -X POST http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments -H "Accept: applica
  tion/json" -H "User-Agent: python-novaclient" -H "OpenStack-API-Version: compute 2.41" -H "X-OpenStack-Nova-API-Version: 2.41" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207b
  d72292" -H "Content-Type: application/json" -d '{"volumeAttachment": {"volumeId": "2fe6c45f-cce9-43ea-90ac-ff0d574121b0"}}'
  DEBUG (connectionpool:400) http://bfeb:8774 "POST /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments HTTP/1.1" 500 210
  DEBUG (session:395) RESP: [500] Openstack-Api-Version: compute 2.41 X-Openstack-Nova-Api-Version: 2.41 Vary: OpenStack-API-Version, X-OpenStack-Nova-API-Version Content-Type: applicatio
  n/json; charset=UTF-8 Content-Length: 210 X-Compute-Request-Id: req-7e934a71-2236-4afa-8d38-6092d11d37fe Date: Tue, 24 Oct 2017 09:23:05 GMT Connection: keep-alive
  RESP BODY: {"computeFault": {"message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'cinderclient.excep
  tions.Unauthorized'>", "code": 500}}

  DEBUG (session:640) POST call to compute for http://bfeb:8774/v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments used request id re
  q-7e934a71-2236-4afa-8d38-6092d11d37fe
  DEBUG (shell:959) Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)
  Traceback (most recent call last):
    File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 957, in main
      OpenStackComputeShell().main(argv)
    File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 879, in main
      args.func(self.cs, args)
    File "/usr/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 2513, in do_volume_attach
      args.device)
    File "/usr/lib/python2.7/dist-packages/novaclient/v2/volumes.py", line 53, in create_server_volume
      body, "volumeAttachment")
    File "/usr/lib/python2.7/dist-packages/novaclient/base.py", line 361, in _create
      resp, body = self.api.client.post(url, body=body)
    File "/usr/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 223, in post
      return self.request(url, 'POST', **kwargs)
    File "/usr/lib/python2.7/dist-packages/novaclient/client.py", line 80, in request
      raise exceptions.from_response(resp, body, url, method)
  ClientException: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)
  ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'cinderclient.exceptions.Unauthorized'> (HTTP 500) (Request-ID: req-7e934a71-2236-4afa-8d38-6092d11d37fe)


  Expected result
  ===============
  The volume is attached to the VM.

  Actual result
  =============
  Cryptic errors are generated.

  Environment
  ===========
  1. Exact version of OpenStack you are running. See the following
    list for all releases: http://docs.openstack.org/releases/

  # dpkg -l |grep nova
  ii  nova-api                             2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - API frontend
  ii  nova-common                          2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - common files
  ii  nova-conductor                       2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - conductor service
  ii  nova-consoleauth                     2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - Console Authenticator
  ii  nova-novncproxy                      2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - NoVNC proxy
  ii  nova-placement-api                   2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - placement API frontend
  ii  nova-scheduler                       2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute - virtual machine scheduler
  ii  python-nova                          2:15.0.6-0ubuntu1~cloud0                   all          OpenStack Compute Python libraries
  ii  python-novaclient                    2:7.1.0-0ubuntu1~cloud0                    all          client library for OpenStack Compute API - Python 2.7

  2. Which hypervisor did you use?
  Libvirt + KVM

  2. Which storage type did you use?
  Ceph

  3. Which networking type did you use?
  Neutron flat network

  Logs & Configs
  ==============
  Relevant part of the nova-api.log

  2017-10-24 11:23:03.320 18537 DEBUG nova.osapi_compute.wsgi.server [req-ba39611c-6ea1-4abf-ae25-786dd1f42082 - - - - -] (18537) accepted ('192.168.46.26', 36478) server /usr/lib/python2
  .7/dist-packages/eventlet/wsgi.py:867
  2017-10-24 11:23:03.377 18537 INFO nova.osapi_compute.wsgi.server [req-4b96f757-a50a-4fd6-b7d3-00b9127297c5 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default d
  efault] 192.168.46.26 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808 HTTP/1.1" status: 404 len: 331 time: 0.0551920
  2017-10-24 11:23:03.391 18537 DEBUG nova.api.openstack.wsgi [req-66b3c7a4-0f07-4692-9172-04587445278d 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default
  ] Calling method '<bound method VersionsController.show of <nova.api.openstack.compute.versionsV21.VersionsController object at 0x7ff888997a50>>' _process_stack /usr/lib/python2.7/dist-
  packages/nova/api/openstack/wsgi.py:626
  2017-10-24 11:23:03.393 18537 INFO nova.osapi_compute.wsgi.server [req-66b3c7a4-0f07-4692-9172-04587445278d 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default d
  efault] 192.168.46.26 "GET /v2.1/ HTTP/1.1" status: 200 len: 711 time: 0.0120900
  2017-10-24 11:23:03.606 18537 DEBUG nova.api.openstack.wsgi [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default
  ] Calling method '<bound method ServersController.show of <nova.api.openstack.compute.servers.ServersController object at 0x7ff888a4bfd0>>' _process_stack /usr/lib/python2.7/dist-packag
  es/nova/api/openstack/wsgi.py:626
  2017-10-24 11:23:03.614 18537 DEBUG nova.compute.api [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] [inst
  ance: cb22727f-32f8-49e9-8136-5395882d259a] Fetching instance by UUID get /usr/lib/python2.7/dist-packages/nova/compute/api.py:2360
  2017-10-24 11:23:03.640 18537 DEBUG oslo_db.sqlalchemy.engines [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default defa
  ult] 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 _check
  _effective_sql_mode /usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:261
  2017-10-24 11:23:03.654 18537 DEBUG oslo_concurrency.lockutils [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default defa
  ult] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:273
  2017-10-24 11:23:03.655 18537 DEBUG oslo_concurrency.lockutils [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:285
  2017-10-24 11:23:03.668 18537 DEBUG oslo_db.sqlalchemy.engines [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 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 _check_effective_sql_mode /usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:261
  2017-10-24 11:23:03.790 18537 DEBUG nova.objects.instance [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lazy-loading 'services' on Instance uuid cb22727f-32f8-49e9-8136-5395882d259a obj_load_attr /usr/lib/python2.7/dist-packages/nova/objects/instance.py:1034
  2017-10-24 11:23:04.594 18537 DEBUG neutronclient.v2_0.client [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] GET call to neutron for http://bfeb:9696/v2.0/ports.json?device_id=cb22727f-32f8-49e9-8136-5395882d259a used request id req-8aaaa9ad-f1ba-43ac-b9dc-bb97a050a1d1 _append_request_id /usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
  2017-10-24 11:23:04.620 18537 DEBUG nova.policy [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'6468f6d82c734776923e367990e8a5f1', 'roles': [u'admin', u'heat_stack_owner'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'2e51fec7c7f1408dbfe01b4eff8b6808', 'project_domain_id': u'default'} authorize /usr/lib/python2.7/dist-packages/nova/policy.py:168
  2017-10-24 11:23:04.695 18537 INFO nova.osapi_compute.wsgi.server [req-0ad9eddf-78c5-404f-91d8-fa412fe1ab85 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 192.168.46.26 "GET /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a HTTP/1.1" status: 200 len: 2267 time: 1.1006789
  2017-10-24 11:23:04.725 18537 DEBUG nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Action: 'create', calling method: <bound method VolumeAttachmentController.create of <nova.api.openstack.compute.volumes.VolumeAttachmentController object at 0x7ff88884a090>>, body: {"volumeAttachment": {"volumeId": "2fe6c45f-cce9-43ea-90ac-ff0d574121b0"}} _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:623
  2017-10-24 11:23:04.741 18537 DEBUG nova.compute.api [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] [instance: cb22727f-32f8-49e9-8136-5395882d259a] Fetching instance by UUID get /usr/lib/python2.7/dist-packages/nova/compute/api.py:2360
  2017-10-24 11:23:04.760 18537 DEBUG oslo_concurrency.lockutils [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:273
  2017-10-24 11:23:04.761 18537 DEBUG oslo_concurrency.lockutils [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Lock "02388e9f-5aab-4301-bc69-ddca16a3ccfb" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:285
  2017-10-24 11:23:04.908 18537 DEBUG oslo_messaging._drivers.amqpdriver [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] CALL msg_id: 259736aee2ca45569a84b1b1acced5f3 exchange 'nova' topic 'compute.bf2' _send /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:442
  2017-10-24 11:23:05.043 18537 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 259736aee2ca45569a84b1b1acced5f3 __call__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:299
  2017-10-24 11:23:05.061 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] REQ: curl -g -i -X GET http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808/volumes/2fe6c45f-cce9-43ea-90ac-ff0d574121b0 -H "X-Service-Token: {SHA1}00e767c36ea5c08c4f5e4dbdbbe788da449a1990" -H "User-Agent: python-cinderclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}3421c89b3c57e1f96ff3c5d9f17e62207bd72292" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:347
  2017-10-24 11:23:05.069 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] RESP: [401] Date: Tue, 24 Oct 2017 09:23:05 GMT Server: Apache/2.4.18 (Ubuntu) x-openstack-request-id: req-f8ce808c-bcae-4729-a48d-2ebd997fd521 WWW-Authenticate: Keystone uri='http://bfeb:5000' Content-Length: 114 Keep-Alive: timeout=5, max=100 Connection: Keep-Alive Content-Type: application/json
  RESP BODY: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}
   _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:395
  2017-10-24 11:23:05.069 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] GET call to cinderv2 for http://bfeb:8776/v2/2e51fec7c7f1408dbfe01b4eff8b6808/volumes/2fe6c45f-cce9-43ea-90ac-ff0d574121b0 used request id req-f8ce808c-bcae-4729-a48d-2ebd997fd521 request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:640
  2017-10-24 11:23:05.075 18537 DEBUG cinderclient.v2.client [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] RESP: [401] Date: Tue, 24 Oct 2017 09:23:05 GMT Server: Apache/2.4.18 (Ubuntu) x-openstack-request-id: req-993ee979-8659-4afd-9db5-e858808d432a WWW-Authenticate: Keystone uri='http://bfeb:5000' Content-Length: 114 Keep-Alive: timeout=5, max=99 Connection: Keep-Alive Content-Type: application/json
  RESP BODY: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}
   _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:395
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Unexpected exception in API method
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 338, in wrapped
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 108, in wrapper
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/volumes.py", line 326, in create
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume_id, device)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 170, in inner
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return function(self, context, instance, *args, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 151, in inner
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return f(self, context, instance, *args, **kw)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3701, in attach_volume
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     disk_bus, device_type)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3644, in _attach_volume
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume_bdm.destroy()
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     self.force_reraise()
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3640, in _attach_volume
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     self._check_attach_and_reserve_volume(context, volume_id, instance)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3624, in _check_attach_and_reserve_volume
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     volume = self.volume_api.get(context, volume_id)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 168, in wrapper
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     res = method(self, ctx, *args, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 190, in wrapper
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     res = method(self, ctx, volume_id, *args, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/volume/cinder.py", line 234, in get
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     item = cinderclient(context).volumes.get(volume_id)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/v2/volumes.py", line 277, in get
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self._get("/volumes/%s" % volume_id, "volume")
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/base.py", line 313, in _get
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     resp, body = self.api.client.get(url)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 164, in get
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self._cs_request(url, 'GET', **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 155, in _cs_request
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     return self.request(url, method, **kwargs)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 144, in request
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions     raise exceptions.from_response(resp, body)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions Unauthorized: The request you have made requires authentication. (HTTP 401)
  2017-10-24 11:23:05.084 18537 ERROR nova.api.openstack.extensions
  2017-10-24 11:23:05.088 18537 INFO nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'cinderclient.exceptions.Unauthorized'>
  2017-10-24 11:23:05.089 18537 DEBUG nova.api.openstack.wsgi [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'cinderclient.exceptions.Unauthorized'> __call__ /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:1039
  2017-10-24 11:23:05.091 18537 INFO nova.osapi_compute.wsgi.server [req-7e934a71-2236-4afa-8d38-6092d11d37fe 6468f6d82c734776923e367990e8a5f1 2e51fec7c7f1408dbfe01b4eff8b6808 - default default] 192.168.46.26 "POST /v2.1/2e51fec7c7f1408dbfe01b4eff8b6808/servers/cb22727f-32f8-49e9-8136-5395882d259a/os-volume_attachments HTTP/1.1" status: 500 len: 579 time: 0.3905520

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1726779/+subscriptions


Follow ups