return 500 when referring an image with status "SAVING"

Bug #1569122 reported by Yushiro FURUKAWA on 2016-04-12
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Glance Client
Undecided
Unassigned
OpenStack Compute (nova)
Low
Unassigned

Bug Description

When I referred an image which is "SAVING" state by using 'nova' command,
it returns 500 error.

[How to reproduce]
1. Create empty image
$ glance image-create --name test --visibility public --disk-format ari

+------------------+--------------------------------------+
| Property | Value |
+------------------+--------------------------------------+
| checksum | None |
| container_format | None |
| created_at | 2016-04-12T01:27:49Z |
| disk_format | ari |
| id | 6d1ce183-e6ed-4dd0-a799-2f1b5abc6b3b |
| min_disk | 0 |
| min_ram | 0 |
| name | test |
| owner | 662765a438ed40a9bc85b82e9f2a2cab |
| protected | False |
| size | None |
| status | queued |
| tags | [] |
| updated_at | 2016-04-12T01:27:49Z |
| virtual_size | None |
| visibility | public |
+------------------+--------------------------------------+

2. Confirm the image status.
$ nova image-list
+--------------------------------------+------+--------+--------+
| ID | Name | Status | Server |
+--------------------------------------+------+--------+--------+
| 6d1ce183-e6ed-4dd0-a799-2f1b5abc6b3b | test | SAVING | |
+--------------------------------------+------+--------+--------+

3. Execute 'nova image-show' or 'nova image-delete'
(This is example of 'nova image-show')
$ nova --debug image-show 6d1ce183-e6ed-4dd0-a799-2f1b5abc6b3b
DEBUG (extension:157) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
DEBUG (extension:157) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
DEBUG (extension:157) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
DEBUG (extension:157) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
DEBUG (extension:157) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
DEBUG (extension:157) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
DEBUG (extension:157) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
DEBUG (extension:157) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
DEBUG (extension:157) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
DEBUG (session:248) REQ: curl -g -i -X GET http://192.168.3.223:5000/v2.0 -H "Accept: application/json" -H "User-Agent: keystoneauth1/2.3.0 python-requests/2.9.1 CPython/2.7.6"
INFO (connectionpool:207) Starting new HTTP connection (1): 192.168.3.223
DEBUG (connectionpool:387) "GET /v2.0 HTTP/1.1" 200 339
DEBUG (session:277) RESP: [200] Content-Length: 339 Vary: X-Auth-Token Keep-Alive: timeout=5, max=100 Server: Apache/2.4.7 (Ubuntu) Connection: Keep-Alive Date: Tue, 12 Apr 2016
01:28:44 GMT Content-Type: application/json x-openstack-request-id: req-bc96ffbe-fe92-4fbe-931e-51c071766609
RESP BODY: {"version": {"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.3.223:5000/v2.0/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}}

DEBUG (v2:63) Making authentication request to http://192.168.3.223:5000/v2.0/tokens
DEBUG (connectionpool:387) "POST /v2.0/tokens HTTP/1.1" 200 3569
DEBUG (session:248) REQ: curl -g -i -X GET http://192.168.3.223:8774/v2.1/662765a438ed40a9bc85b82e9f2a2cab -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-
Auth-Token: {SHA1}d52cbbc7997c02255185fbf06a3c608866de4091"
INFO (connectionpool:207) Starting new HTTP connection (1): 192.168.3.223
DEBUG (connectionpool:387) "GET /v2.1/662765a438ed40a9bc85b82e9f2a2cab HTTP/1.1" 404 52
DEBUG (session:277) RESP: [404] Date: Tue, 12 Apr 2016 01:28:44 GMT Connection: keep-alive Content-Type: text/plain; charset=UTF-8 Content-Length: 52 X-Compute-Request-Id: req-3c
c87b6b-21c1-4c75-ada3-2bb7a6441267
RESP BODY: 404 Not Found

The resource could not be found.

DEBUG (session:248) REQ: curl -g -i -X GET http://192.168.3.223:8774/v2.1/ -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}d52cbbc7997c02
255185fbf06a3c608866de4091"
DEBUG (connectionpool:387) "GET /v2.1/ HTTP/1.1" 200 387
DEBUG (session:277) RESP: [200] Content-Length: 387 X-Compute-Request-Id: req-9d6fa002-6769-4c7b-b8a6-70a9e7b4a270 Vary: X-OpenStack-Nova-API-Version Connection: keep-alive X-Ope
nstack-Nova-Api-Version: 2.1 Date: Tue, 12 Apr 2016 01:28:44 GMT Content-Type: application/json
RESP BODY: {"version": {"status": "CURRENT", "updated": "2013-07-23T11:33:21Z", "links": [{"href": "http://192.168.3.223:8774/v2.1/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}], "min_version": "2.1", "version": "2.26", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.compute+json;version=2.1"}], "id": "v2.1"}}

DEBUG (extension:157) found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token')
DEBUG (extension:157) found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken')
DEBUG (extension:157) found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode')
DEBUG (extension:157) found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password')
DEBUG (extension:157) found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password')
DEBUG (extension:157) found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword')
DEBUG (extension:157) found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token')
DEBUG (extension:157) found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token')
DEBUG (extension:157) found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password')
DEBUG (session:248) REQ: curl -g -i -X GET http://192.168.3.223:8774/v2.1/662765a438ed40a9bc85b82e9f2a2cab/images/6d1ce183-e6ed-4dd0-a799-2f1b5abc6b3b -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-OpenStack-Nova-API-Version: 2.25" -H "X-Auth-Token: {SHA1}d52cbbc7997c02255185fbf06a3c608866de4091"
DEBUG (connectionpool:387) "GET /v2.1/662765a438ed40a9bc85b82e9f2a2cab/images/6d1ce183-e6ed-4dd0-a799-2f1b5abc6b3b HTTP/1.1" 500 198
DEBUG (session:277) RESP: [500] Content-Length: 198 X-Compute-Request-Id: req-fd6835d9-50df-40a3-993f-1f71798966cc Vary: X-OpenStack-Nova-API-Version Connection: keep-alive X-Openstack-Nova-Api-Version: 2.25 Date: Tue, 12 Apr 2016 01:28:45 GMT Content-Type: application/json; charset=UTF-8
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<type 'exceptions.AttributeError'>", "code": 500}}

DEBUG (shell:1082) Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.AttributeError'> (HTTP 500) (Request-ID: req-fd6835d9-50df-40a3-993f-1f71798966cc)
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/novaclient/shell.py", line 1080, in main
    OpenStackComputeShell().main(argv)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/shell.py", line 1007, in main
    args.func(self.cs, args)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 1304, in do_image_show
    image = _find_image(cs, args.image)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 2139, in _find_image
    return utils.find_resource(cs.images, image)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/utils.py", line 294, in find_resource
    return manager.get(tmp_id)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/images.py", line 55, in get
    return self._get("/images/%s" % base.getid(image), "image")
  File "/usr/local/lib/python2.7/dist-packages/novaclient/base.py", line 339, in _get
    resp, body = self.api.client.get(url)
  File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 173, in get
    return self.request(url, 'GET', **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 94, 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.
<type 'exceptions.AttributeError'> (HTTP 500) (Request-ID: req-fd6835d9-50df-40a3-993f-1f71798966cc)
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.AttributeError'> (HTTP 500) (Request-ID: req-fd6835d9-50df-40a3-993f-1f71798966cc)
$

[n-api.log]
2016-04-12 10:28:45.824 ERROR nova.api.openstack.extensions [req-fd6835d9-50df-40a3-993f-1f71798966cc admin admin] Unexpected exception in API method
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions Traceback (most recent call last):
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions return f(*args, **kwargs)
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/images.py", line 87, in show
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions image = self._image_api.get(context, id)
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/image/api.py", line 93, in get
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions show_deleted=show_deleted)
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/image/glance.py", line 283, in show
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions include_locations=include_locations)
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/image/glance.py", line 513, in _translate_from_glance
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions include_locations=include_locations)
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/image/glance.py", line 597, in _extract_attributes
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions output[attr] = getattr(image, attr) or 0
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/glanceclient/openstack/common/apiclient/base.py", line 490, in __getattr__
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions self.get()
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/glanceclient/openstack/common/apiclient/base.py", line 512, in get
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions {'x_request_id': self.manager.client.last_request_id})
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions AttributeError: 'HTTPClient' object has no attribute 'last_request_id'
2016-04-12 10:28:45.824 TRACE nova.api.openstack.extensions
2016-04-12 10:28:45.826 INFO nova.api.openstack.wsgi [req-fd6835d9-50df-40a3-993f-1f71798966cc admin admin] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

tags: added: glanceclient
removed: glance
Sirisha (sirisha-1) on 2016-04-12
Changed in nova:
assignee: nobody → Sirisha (sirisha-1)
Sirisha (sirisha-1) on 2016-04-12
Changed in nova:
assignee: Sirisha (sirisha-1) → nobody
Sylvain Bauza (sylvain-bauza) wrote :

Per the n-api logs, it seems the problem is related to glanceclient rather than Nova.

Changed in nova:
status: New → Invalid
Sirisha (sirisha-1) wrote :

Hi,

I think the bug is valid in nova itself

Changed in nova:
assignee: nobody → Sirisha (sirisha-1)
status: Invalid → Confirmed
Changed in python-glanceclient:
status: New → Invalid

Fix proposed to branch: master
Review: https://review.openstack.org/305255

Changed in nova:
status: Confirmed → In Progress
Sylvain Bauza (sylvain-bauza) wrote :

That really looks weird. The glance wrapper in Nova can surely hide the exception, but that doesn't really fix the problem, right?

Accepting the bug in Nova for the moment, but I'm not very sold to that.

Changed in nova:
importance: Undecided → Low
Sirisha (sirisha-1) on 2016-04-15
Changed in python-glanceclient:
status: Invalid → New
Sirisha (sirisha-1) wrote :

Hi Sylvain Bauza,

As you have told yes its hiding the error not only of size attribute but of all attributes and also as you proposed earlier this is an glance client issue as per n-api logs.

The error is because of the below line in glanceclient/openstack/common/apiclient/base.py : line 512

and if comment it everthing works fine even without any changes in nova.

I am unable to understand why is that line present. Could you please help me out?

Thanks in advance

Regards
Sirisha

Sirisha (sirisha-1) wrote :

 If the error is resolved at glance client end, as the image is in saving state the size attribute is not returned from glance at that point of time we will get size not found Attribute Error in stack trace so in that case we should return None and this changes should be made in nova.

Correct me if I am wrong

wangolo (wangoloj) wrote :

Happens to me but on the different way, when i try to create a new server using a python script

new_server = nova.servers.create(name="TestServer", image=images[0], flavor=flavors[0])

On the nova-api side this error happends.

2016-05-02 13:46:28.334 29855 ERROR nova.api.openstack.extensions {'x_request_id': self.manager.client.last_request_id})
2016-05-02 13:46:28.334 29855 ERROR nova.api.openstack.extensions AttributeError: 'HTTPClient' object has no attribute 'last_request_id'
2016-05-02 13:46:28.334 29855 ERROR nova.api.openstack.extensions
2016-05-02 13:46:28.337 29855 INFO nova.api.openstack.wsgi [req-a4815023-0600-49ad-a7bb-af39f74d1016 99260c1b97004777ab2e90254f8fd883 b51978f114574d6e8136daf4b6456f82 - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.AttributeError'>
2016-05-02 13:46:28.339 29855 INFO nova.osapi_compute.wsgi.server [req-a4815023-0600-49ad-a7bb-af39f74d1016 99260c1b97004777ab2e90254f8fd883 b51978f114574d6e8136daf4b6456f82 - - -] 192.168.1.2 "POST /v2/b51978f114574d6e8136daf4b6456f82/servers HTTP/1.1" status: 500 len: 429 time: 0.0923460

Change abandoned by Michael Still (<email address hidden>) on branch: master
Review: https://review.openstack.org/305255
Reason: This patch has been sitting unchanged for more than 12 weeks. I am therefore going to abandon it to keep the nova review queue sane. Please feel free to restore the change if you're still working on it.

Sirisha (sirisha-1) on 2016-12-26
Changed in nova:
assignee: Sirisha (sirisha-1) → nobody
Changed in nova:
status: In Progress → Confirmed

Not reproducible any more

Changed in python-glanceclient:
status: New → Invalid
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers