Closed albertomolina closed 8 years ago
Enabling debug mode in nova.conf shows these logs:
2016-05-30 18:48:28.323 30466 DEBUG keystoneauth.session [-] REQ: curl -g -i -X GET http://192.168.221.101:35357 -H "Accept: application/json" -H "User-Agent: nova/13.0.0 keystonemiddleware.auth_token/4.4.0 keystoneauth1/2.4.0 python-requests/2.9.1 CPython/2.7.9" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-05-30 18:48:28.359 30466 DEBUG keystoneauth.session [-] RESP: [300] Content-Length: 601 Vary: X-Auth-Token Keep-Alive: timeout=5, max=100 Server: Apache/2.4.10 (Debian) Connection: Keep-Alive Date: Mon, 30 May 2016 18:48:28 GMT Content-Type: application/json RESP BODY: {"versions": {"values": [{"status": "stable", "updated": "2016-04-04T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.6", "links": [{"href": "http://192.168.221.101:35357/v3/", "rel": "self"}]}, {"status": "stable", "updated": "2014-04-17T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v2.0+json"}], "id": "v2.0", "links": [{"href": "http://192.168.221.101:35357/v2.0/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}]}} _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-05-30 18:48:28.363 30466 DEBUG keystoneauth.identity.v3.base [-] Making authentication request to http://192.168.221.101:35357/v3/auth/tokens get_auth_ref /usr/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py:165
2016-05-30 18:48:28.801 30466 DEBUG keystoneauth.session [-] REQ: curl -g -i -X GET http://192.168.221.101:35357/v3 -H "Accept: application/json" -H "User-Agent: nova/13.0.0 keystonemiddleware.auth_token/4.4.0 keystoneauth1/2.4.0 python-requests/2.9.1 CPython/2.7.9" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-05-30 18:48:28.817 30466 DEBUG keystoneauth.session [-] RESP: [200] Content-Length: 255 Vary: X-Auth-Token Keep-Alive: timeout=5, max=98 Server: Apache/2.4.10 (Debian) Connection: Keep-Alive Date: Mon, 30 May 2016 18:48:28 GMT Content-Type: application/json x-openstack-request-id: req-de1e6269-a55c-4e88-aa57-666a34f6dec6 RESP BODY: {"version": {"status": "stable", "updated": "2016-04-04T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.6", "links": [{"href": "http://192.168.221.101:35357/v3/", "rel": "self"}]}} _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-05-30 18:48:28.828 30466 DEBUG keystoneauth.session [-] REQ: curl -g -i -X GET http://192.168.221.101:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}0ea2d0181a332d479ed670c396d2677cd439a298" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-05-30 18:48:29.394 30466 DEBUG keystoneauth.session [-] RESP: [200] Content-Length: 3934 X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76 Vary: X-Auth-Token Keep-Alive: timeout=5, max=97 Server: Apache/2.4.10 (Debian) Connection: Keep-Alive Date: Mon, 30 May 2016 18:48:28 GMT Content-Type: application/json x-openstack-request-id: req-24b865a2-45f9-4bcc-acac-a633160837a6 RESP BODY: {"token": {"methods": ["password"], "roles": [{"id": "e025cc04f4b849dbaa3aacd1794732fa", "name": "user"}], "expires_at": "2016-05-30T19:48:28.278864Z", "project": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "8f94622b8ed74ff89a244a5432e72cf8", "name": "demo"}, "catalog": "<removed>", "user": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "7ee389f723c2495bb7d8cefba75a0ef7", "name": "demo"}, "audit_ids": ["7MdzLcJfRoag27nbMMu16A"], "issued_at": "2016-05-30T18:48:28.000000Z"}} _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-05-30 18:48:29.402 30466 DEBUG oslo_policy._cache_handler [req-dcc1c5ad-4f05-4f33-a60a-34c1c900658c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] Reloading cached file /etc/nova/policy.json read_cached_file /usr/lib/python2.7/dist-packages/oslo_policy/_cache_handler.py:38
2016-05-30 18:48:29.419 30466 DEBUG oslo_policy.policy [req-dcc1c5ad-4f05-4f33-a60a-34c1c900658c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] Reloaded policy file: /etc/nova/policy.json _load_policy_file /usr/lib/python2.7/dist-packages/oslo_policy/policy.py:493
2016-05-30 18:48:31.149 30466 INFO nova.osapi_compute.wsgi.server [req-dcc1c5ad-4f05-4f33-a60a-34c1c900658c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] 192.168.1.201 "GET /v2.1/8f94622b8ed74ff89a244a5432e72cf8 HTTP/1.1" status: 404 len: 264 time: 2.8460031
2016-05-30 18:48:31.155 30466 DEBUG keystoneauth.session [req-dcc1c5ad-4f05-4f33-a60a-34c1c900658c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] REQ: curl -g -i -X GET http://192.168.221.101:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}0ea2d0181a332d479ed670c396d2677cd439a298" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-05-30 18:48:31.944 30466 DEBUG keystoneauth.session [req-dcc1c5ad-4f05-4f33-a60a-34c1c900658c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] RESP: [200] Content-Length: 3934 X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76 Vary: X-Auth-Token Keep-Alive: timeout=5, max=96 Server: Apache/2.4.10 (Debian) Connection: Keep-Alive Date: Mon, 30 May 2016 18:48:31 GMT Content-Type: application/json x-openstack-request-id: req-a41a2ed0-2909-4077-a1cc-2187afcf1fcb RESP BODY: {"token": {"methods": ["password"], "roles": [{"id": "e025cc04f4b849dbaa3aacd1794732fa", "name": "user"}], "expires_at": "2016-05-30T19:48:28.278864Z", "project": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "8f94622b8ed74ff89a244a5432e72cf8", "name": "demo"}, "catalog": "<removed>", "user": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "7ee389f723c2495bb7d8cefba75a0ef7", "name": "demo"}, "audit_ids": ["7MdzLcJfRoag27nbMMu16A"], "issued_at": "2016-05-30T18:48:28.000000Z"}} _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-05-30 18:48:31.963 30466 DEBUG nova.api.openstack.wsgi [req-e5fe7501-d614-4271-b5d7-18c0f51eb54c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] Calling method '<bound method VersionsController.show of <nova.api.openstack.compute.versionsV21.VersionsController object at 0x7fd0b3840f50>>' _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:699
2016-05-30 18:48:31.975 30466 INFO nova.osapi_compute.wsgi.server [req-e5fe7501-d614-4271-b5d7-18c0f51eb54c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] 192.168.1.201 "GET /v2.1/ HTTP/1.1" status: 200 len: 655 time: 0.8214250
2016-05-30 18:48:32.270 30466 DEBUG keystoneauth.session [req-e5fe7501-d614-4271-b5d7-18c0f51eb54c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] REQ: curl -g -i -X GET http://192.168.221.101:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}0ea2d0181a332d479ed670c396d2677cd439a298" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-05-30 18:48:32.881 30466 DEBUG keystoneauth.session [req-e5fe7501-d614-4271-b5d7-18c0f51eb54c 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] RESP: [200] Content-Length: 3934 X-Subject-Token: {SHA1}11f86499755bfb27f4151c984358edc422bfdf76 Vary: X-Auth-Token Keep-Alive: timeout=5, max=95 Server: Apache/2.4.10 (Debian) Connection: Keep-Alive Date: Mon, 30 May 2016 18:48:32 GMT Content-Type: application/json x-openstack-request-id: req-076bdf10-8e5c-41e3-8d39-3df73766be3c RESP BODY: {"token": {"methods": ["password"], "roles": [{"id": "e025cc04f4b849dbaa3aacd1794732fa", "name": "user"}], "expires_at": "2016-05-30T19:48:28.278864Z", "project": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "8f94622b8ed74ff89a244a5432e72cf8", "name": "demo"}, "catalog": "<removed>", "user": {"domain": {"id": "5c1ea4ef36f64793aab329d956dd4193", "name": "default"}, "id": "7ee389f723c2495bb7d8cefba75a0ef7", "name": "demo"}, "audit_ids": ["7MdzLcJfRoag27nbMMu16A"], "issued_at": "2016-05-30T18:48:28.000000Z"}} _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-05-30 18:48:32.890 30466 DEBUG nova.api.openstack.wsgi [req-2a436e20-a1f8-4957-84d1-3b44e5495314 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] Calling method '<bound method ImagesController.detail of <nova.api.openstack.compute.images.ImagesController object at 0x7fd0b3bdf550>>' _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:699
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions [req-2a436e20-a1f8-4957-84d1-3b44e5495314 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] Unexpected exception in API method
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 478, in wrapped
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/images.py", line 145, in detail
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions **page_params)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/nova/image/api.py", line 68, in get_all
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions return session.detail(context, **kwargs)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 300, in detail
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions for image in images:
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 254, in list
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions for image in paginate(params, return_request_id):
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 238, in paginate
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions images, resp = self._list(url, "images")
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 63, in _list
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions resp, body = self.client.get(url)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 275, in get
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions return self._request('GET', url, **kwargs)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 267, in _request
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions resp, body_iter = self._handle_response(resp)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 83, in _handle_response
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions raise exc.from_response(resp, resp.content)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions HTTPInternalServerError: 500 Internal Server Error: The server has either erred or is incapable of performing the requested operation. (HTTP 500)
2016-05-30 18:48:34.020 30466 ERROR nova.api.openstack.extensions
2016-05-30 18:48:34.031 30466 INFO nova.api.openstack.wsgi [req-2a436e20-a1f8-4957-84d1-3b44e5495314 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible. <class 'glanceclient.exc.HTTPInternalServerError'>
2016-05-30 18:48:34.040 30466 DEBUG nova.api.openstack.wsgi [req-2a436e20-a1f8-4957-84d1-3b44e5495314 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] 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 'glanceclient.exc.HTTPInternalServerError'> __call__ /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:1070
2016-05-30 18:48:34.056 30466 INFO nova.osapi_compute.wsgi.server [req-2a436e20-a1f8-4957-84d1-3b44e5495314 7ee389f723c2495bb7d8cefba75a0ef7 8f94622b8ed74ff89a244a5432e72cf8 - - -] 192.168.1.201 "GET /v2.1/8f94622b8ed74ff89a244a5432e72cf8/images/detail HTTP/1.1" status: 500 len: 517 time: 1.7883658
Both openstack and glance clients are allowed to show images available (none at this moment):
But nova throws an error:
The issue seems to be related to kesytone v3 because keystone.log shows this trace: