Liberty - Unexpected exception in API method

[Thiyagu]

This is 3 Node Liberty setup (controller, Network and Compute) configured with neutron Network option 2 : Self servicing network and is with openvswitch.
I found everything is working fine except while launching instance I'm getting error as follows , By tracing keystone.log and nova-api.log and based on time stamp I see Keystone fails the authentication followed by nova-api started throwing the exception errors.

Attached the config files and logs for you reference ... Request you to help me ASAP.

Controller: 10.182.131.93
Network: 10.182.131.84
Compute: 10.182.131.87

Thank You

******************************************************
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions [req-61818a91-ddff-4d25-8855-0dcde336e6b0 1cd7f867708b46e0a795abad8a7a66c3 6e6b9259a526447fa4274442b81c3b55 - - -] Unexpected exception in API method
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/openstack/extensions.py", line 478, in wrapped
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/validation/__init__.py", line 73, in wrapper
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/validation/__init__.py", line 73, in wrapper
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 611, in create
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions **create_kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/hooks.py", line 149, in inner
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions rv = f(*args, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1581, in create
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions check_server_group_quota=check_server_group_quota)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1181, in _create_instance
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions auto_disk_config, reservation_id, max_count)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 955, in _validate_and_build_base_options
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions pci_request_info, requested_networks)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1059, in create_pci_requests_for_sriov_ports
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions neutron = get_client(context, admin=True)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 237, in get_client
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions auth_token = _ADMIN_AUTH.get_token(_SESSION)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/base.py", line 200, in get_token
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return self.get_access(session).auth_token
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/base.py", line 240, in get_access
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions self.auth_ref = self.get_auth_ref(session)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/generic/base.py", line 186, in get_auth_ref
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return self._plugin.get_auth_ref(session, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/auth/identity/v3/base.py", line 190, in get_auth_ref
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions authenticated=False, log=False, **rkwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 501, in post
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return self.request(url, 'POST', **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/utils.py", line 337, in inner
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/keystoneclient/session.py", line 401, in request
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions raise exceptions.from_response(resp, method, url)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-d2ea540d-cdbc-44b9-bbed-ab2fc92ebbe4)
2016-02-23 18:46:50.042 17814 ERROR nova.api.openstack.extensions
2016-02-23 18:46:50.048 17814 INFO nova.api.openstack.wsgi [req-61818a91-ddff-4d25-8855-0dcde336e6b0 1cd7f867708b46e0a795abad8a7a66c3 6e6b9259a526447fa4274442b81c3b55 - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'keystoneclient.exceptions.Unauthorized'>
******************************************************

[Thiyagu (thiyagu-j)]

Hi I got the authorization issue fixed by changing the below fields in /etc/nova/nova.conf. But still the API error exist ....

[neutron]
auth_strategy = keystone
admin_auth_url = http:////controller.engba.symantec.com:35357/v2.0
admin_tenant_name = service
admin_username = neutron
admin_password = neutron_pass
url = http://controller.engba.symantec.com:9696
service_metadata_proxy = True
metadata_proxy_shared_secret = 123456789987654321

[jichenjc (jichenjc)]

is the traceback of the exception same to #1 you added after you change the configuration?

[Markus Zoeller (markus_z) (mzoeller)]

@Thiyagu:

Please answer ichenjc's question in comment #3. Attaching the new log
would be helpful. After you provided an answer, please switch the
bug report back to "new".

[Eyal Traitel (eyal-i)]

I am encountering a similar failure on a single server devstack setup on Ubuntu. I don’t see an error in keystone.log. Attaching logs and configs.

=== key.log (last lines):
…
2016-04-07 12:38:26.217 14348 DEBUG keystone.policy.backends.rules [req-b03c8491-5591-433b-a79a-d0210d303787 12cbf8c425e64bd49336482ca6717802 19fec374ca7347cb8772fe1a9a549b56 - default default] enforce identity:validate_token
: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'12cbf8c425e64bd49336482ca6717802', 'roles': [u'service'], 'user_domain_id': u'default', 'trustee_id': None, 'trustor_id': None, 'consumer_id': None, 'token'
: <KeystoneToken (audit_id=r10GJXEMT768UYY8GUVuVA, audit_chain_id=r10GJXEMT768UYY8GUVuVA) at 0x7f161e7ad618>, 'project_id': u'19fec374ca7347cb8772fe1a9a549b56', 'trust_id': None, 'project_domain_id': u'default'} 2016-04-07 12
:38:26.217 enforce /opt/stack/keystone/keystone/policy/backends/rules.py:76
2016-04-07 12:38:26.218 14348 DEBUG keystone.common.controller [req-b03c8491-5591-433b-a79a-d0210d303787 12cbf8c425e64bd49336482ca6717802 19fec374ca7347cb8772fe1a9a549b56 - default default] RBAC: Authorization granted 2016-04
-07 12:38:26.218 inner /opt/stack/keystone/keystone/common/controller.py:180

=== nova.log:
2016-04-07 12:38:25.154 DEBUG keystoneauth.session [req-62c3900e-926c-44ec-a9d0-d3aafa68359d admin demo] REQ: curl -g -i -X GET http://172.18.3.86:9696/v2.0/ports.json?fields=id&tenant_id=44989b6d94ab4468b8c27dc730a7e9e4 -H $
2016-04-07 12:38:25.416 DEBUG keystoneauth.session [req-62c3900e-926c-44ec-a9d0-d3aafa68359d admin demo] RESP: [200] Date: Thu, 07 Apr 2016 09:38:25 GMT Connection: keep-alive Content-Type: application/json; charset=UTF-8 Co$
RESP BODY: {"ports": [{"id": "b983aef5-9c96-40f7-b209-ea40e6c8f73d"}, {"id": "d7bf4ace-c4a5-42d8-8a81-aa9fdbd65678"}, {"id": "e91a6d11-c89a-41ef-882f-95e19697b5b6"}]}
 from (pid=12448) _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-04-07 12:38:26.410 ERROR nova.api.openstack.extensions [req-62c3900e-926c-44ec-a9d0-d3aafa68359d admin demo] Unexpected exception in API method
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions Traceback (most recent call last):
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions return f(*args, **kwargs)
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions return func(*args, **kwargs)
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions return func(*args, **kwargs)
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions return func(*args, **kwargs)
2016-04-07 12:38:26.410 TRACE nova.api.openstack.extensions ...

[Laszlo Hegedus (laszlo-hegedus)]

From the n-api.log it seems that the block device destination type in block_device_mapping_v2 gets messed up somewhere. I think it should only be 'volume', but the id is appended at the end.

[Sean Dague (sdague)]

Right, I don't see any actual Authentication issues in the log, only issues of setting the incorrect volume id format.

[Launchpad Janitor (janitor)]

[Expired for OpenStack Compute (nova) because there has been no activity for 60 days.]