Nova is returning 500 for GET on floating-ip

Bug #1431751 reported by Nikita Konovalov
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Mirantis OpenStack
Invalid
Undecided
Unassigned

Bug Description

While testing Sahara @ 25 Nodes scale lab the following error was reproducing constantly.

The error prevents Sahara from starting/deleting clusters correctly.

182>Mar 10 10:41:46 node-7 nova-api 192.168.0.2 "GET /v2/f337c328bd9847058552c894fe4a485c/os-floating-ips HTTP/1.1" status: 500 len: 354 time: 0.5400200
<183>Mar 10 10:41:46 node-7 nova-api
REQ: curl -i http://192.168.0.2:9696/v2.0/ports.json?device_id=cc077863-5f95-49fb-91eb-5f9e97251d66 -X GET -H "X-Auth-Token: 03cc39cec9884e118f9a4aa3914fbb1a" -H "User-Agent: python-neutronclient"
<183>Mar 10 10:41:46 node-7 nova-api RESP:200 CaseInsensitiveDict({'date': 'Tue, 10 Mar 2015 10:41:46 GMT', 'connection': 'close', 'content-type': 'application/json; charset=UTF-8', 'content-length': '578', 'x-openstack-request-id': 'req-7e187c34-c43e-4d78-a596-d4355f6906da'}) {"ports": [{"status": "DOWN", "name": "", "allowed_address_pairs": [], "admin_state_up": true, "network_id": "9fb2a7a8-8565-40e3-8ad8-392c5b8fdc85", "tenant_id": "2dc8d7d3e5d748c3952ded0fac5c6a0f", "extra_dhcp_opts": [], "binding:vnic_type": "normal", "device_owner": "compute:None", "mac_address": "fa:16:3e:81:a4:25", "fixed_ips": [{"subnet_id": "2e157ea9-b018-4995-b089-8090b5670feb", "ip_address": "10.2.11.7"}], "id": "14ee37d9-1b83-40e8-9865-9ce5f5861ee6", "security_groups": ["91426313-148a-4176-89d0-7901e29a1558"], "device_id": "cc077863-5f95-49fb-91eb-5f9e97251d66"}]}
<183>Mar 10 10:41:46 node-7 nova-api
REQ: curl -i http://192.168.0.2:9696/v2.0/security-groups.json?id=91426313-148a-4176-89d0-7901e29a1558 -X GET -H "X-Auth-Token: 03cc39cec9884e118f9a4aa3914fbb1a" -H "User-Agent: python-neutronclient"
...skipping...
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack Traceback (most recent call last):
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 124, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return req.get_response(self.application)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1296, in send
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack application, catch_exc_info=False)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/request.py", line 1260, in call_application
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return resp(environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/keystonemiddleware/auth_token.py", line 748, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return self._call_app(env, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/keystonemiddleware/auth_token.py", line 684, in _call_app
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return self._app(env, _fake_start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return resp(environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return resp(environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/routes/middleware.py", line 131, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack response = self.app(environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 144, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return resp(environ, start_response)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 130, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/webob/dec.py", line 195, in call_func
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 910, in __call__
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack content_type, body, accept)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 975, in _process_stack
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1059, in dispatch
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack return method(req=request, **action_args)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/contrib/floating_ips.py", line 130, in index
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack floating_ips = self.network_api.get_floating_ips_by_project(context)
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/neutronv2/api.py", line 1100, in get_floating_ips_by_project
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack for fip in fips]
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/network/neutronv2/api.py", line 1078, in _format_floating_ip_model
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack instance_uuid = port_dict[fip['port_id']]['device_id']
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack KeyError: u'407665f7-4f53-4ec3-917a-429e22893135'
2015-03-10 10:42:16.047 9685 TRACE nova.api.openstack
<182>Mar 10 10:42:16 node-7 nova-api http://172.16.46.55:8774/v2/2dc8d7d3e5d748c3952ded0fac5c6a0f/os-floating-ips returned with HTTP 500
<183>Mar 10 10:42:16 node-7 nova-api
REQ: curl -i http://192.168.0.2:9696/v2.0/security-groups.json?id=c7d2df18-3ced-46e3-9504-cc1aefaea350 -X GET -H "X-Auth-Token: c5b8b52506aa4e07984e6f72beb087af" -H "User-Agent: python-neutronclient"
<183>Mar 10 10:42:16 node-7 nova-api Returning 500 to user: The server has either erred or is incapable of performing the requested operation.
<182>Mar 10 10:42:16 node-7 nova-api 192.168.0.2 "GET /v2/2dc8d7d3e5d748c3952ded0fac5c6a0f/os-floating-ips HTTP/1.1" status: 500 len: 354 time: 0.1414189

MOS 6.0.1_130
Networking: Neutron GRE

Revision history for this message
Roman Podoliaka (rpodolyaka) wrote :

Nikita, could you please elaborate on what scenarios you've been running and provide additional logs?

Looking at the info you've posted it's not clear to me what 407665f7-4f53-4ec3-917a-429e22893135 uuid corresponds to...

Changed in mos:
status: New → Incomplete
Changed in mos:
milestone: none → 6.1
Revision history for this message
Nikita Konovalov (nkonovalov) wrote :

I cannot provide the diagnostic snapshot for that env, so setting this to invalid. If reproduces again on a new env I'll reopen it with more details.

Changed in mos:
status: Incomplete → Invalid
Revision history for this message
Eugene Nikanorov (enikanorov) wrote :

Hello from 2019. This still reproduces on liberty :)

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.