Calling GET v3/os-cells/capacities causes an 'Unexpected API Error.'

[Masayuki Igawa]

When I called Nova V3 API 'GET v3/os-cells/capacities', an 'Unexpected API Error.' occurred.

http://logs.openstack.org/57/78157/1/check/check-tempest-dsvm-full/bcb3b6b/console.html#_2014-03-05_11_56_34_285
console.html
------------------------------------------------------------------------------------------------------------------------------------------
2014-03-05 11:56:34.283 | pythonlogging:'': {{{
2014-03-05 11:56:34.283 | 2014-03-05 11:30:18,083 Request: POST http://127.0.0.1:5000/v2.0/tokens
2014-03-05 11:56:34.283 | 2014-03-05 11:30:18,083 Request Headers: {'Content-Type': 'application/json', 'Accept': 'application/json'}
2014-03-05 11:56:34.284 | 2014-03-05 11:30:18,083 Request Body: {"auth": {"tenantName": "CellsV3Test-1270506035", "passwordCredentials": {"username": "CellsV3Test-365545871", "password": "pass"}}}
2014-03-05 11:56:34.284 | 2014-03-05 11:30:18,312 Response Status: 200
2014-03-05 11:56:34.284 | 2014-03-05 11:30:18,312 Response Headers: {'content-length': '10648', 'date': 'Wed, 05 Mar 2014 11:30:18 GMT', 'content-type': 'application/json', 'vary': 'X-Auth-Token', 'connection': 'close'}
2014-03-05 11:56:34.284 | 2014-03-05 11:30:18,312 Response Body: {"access": {"token": {"issued_at": "2014-03-05T11:30:18.255082", "expires": "2014-03-05T12:30:18Z", "id": "<TOKEN>
2014-03-05 11:56:34.284 | 2014-03-05 11:30:18,312 Large body (10648) md5 summary: a72282e83c228bfcf861c768bbcbdf79
2014-03-05 11:56:34.285 | 2014-03-05 11:30:18,313 Request: GET http://127.0.0.1:8774/v3/os-cells/capacities
2014-03-05 11:56:34.285 | 2014-03-05 11:30:18,313 Request Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<Token omitted>'}
2014-03-05 11:56:34.285 | 2014-03-05 11:31:18,373 Response Status: 500
2014-03-05 11:56:34.285 | 2014-03-05 11:31:18,373 Nova/Cinder request id: req-ae22c360-c3b8-4ad5-86d1-37e5664fb9ea
2014-03-05 11:56:34.285 | 2014-03-05 11:31:18,373 Response Headers: {'content-length': '216', 'date': 'Wed, 05 Mar 2014 11:31:18 GMT', 'content-type': 'application/json; charset=UTF-8', 'connection': 'close'}
2014-03-05 11:56:34.285 | 2014-03-05 11:31:18,373 Response 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 'oslo.messaging.exceptions.MessagingTimeout'>", "code": 500}}
2014-03-05 11:56:34.285 | }}}
------------------------------------------------------------------------------------------------------------------------------------------

Full logs are:
http://logs.openstack.org/57/78157/1/check/check-tempest-dsvm-full/bcb3b6b

[Christopher Yeoh (cyeoh-0)]

This is the corresponding nova-api log message.

2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions Traceback (most recent call last):
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/openstack/extensions.py", line 472, in wrapped
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions return f(*args, **kwargs)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/openstack/compute/plugins/v3/cells.py", line 152, in capacities
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions cell_name=id)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/nova/nova/cells/rpcapi.py", line 349, in get_capacities
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions return cctxt.call(ctxt, 'get_capacities', cell_name=cell_name)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/client.py", line 150, in call
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions wait_for_reply=True, timeout=timeout)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/transport.py", line 90, in _send
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions timeout=timeout)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 409, in send
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions return self._send(target, ctxt, message, wait_for_reply, timeout)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 400, in _send
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions result = self._waiter.wait(msg_id, timeout)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 267, in wait
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions reply, ending = self._poll_connection(msg_id, timeout)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 217, in _poll_connection
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions % msg_id)
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions MessagingTimeout: Timed out waiting for a reply to message ID 47f8ba13bf9841d5a24c6339e0f2561c
2014-03-05 11:31:18.368 27772 TRACE nova.api.openstack.extensions

It looks like cells is not configured for the test system as the rpc is timing out. We could handle MessagingTimeout exceptions, but I think theoretically we'd have to handle that for every rpc call. I think for tempest though we should not be calling the cells API unless we know the target system is configured with cells enabled. Maybe we should catch this all earlier if cells is not enabled

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/81155
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=dcc760238053da90ac1b83212a004f67fffebee2
Submitter: Jenkins
Branch: master

commit dcc760238053da90ac1b83212a004f67fffebee2
Author: Christopher Yeoh <email address hidden>
Date: Tue Mar 18 14:16:28 2014 +1100

    Cells API calls return 501 when cells disabled

    When cells is not enabled the cells API calls should return
    a 501 NotImplemented rather than have the internals
    eventually raise various errors which may include timeout
    errors.

    +DocImpact: cells API calls will now return a 501 if cells is disabled
    Closes-Bug: 1288214

    Change-Id: I07e69bbe11ec88cd3f07b47846f3a0a5c9e6f3dc