Public bug reported: The issue usually not fatal, but nova MUST not return 500 on these requests.
http://logs.openstack.org/73/104673/6/check/check-tempest-dsvm-neutron-full/a1ee0ee/logs/screen-n-api.txt.gz#_2014-07-22_17_15_25_548 2014-07-22 17:15:25.547 AUDIT nova.api.openstack.compute.contrib.server_external_events [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Create event network-vif-plugged:52f5dc11-1e59-48fe-867c-e059b5c652c6 for instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 ERROR nova.api.openstack [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Caught error: Unable to find host for Instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack Traceback (most recent call last): 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 121, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return req.get_response(self.application) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack application, catch_exc_info=False) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack app_iter = application(self.environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 559, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return self._app(env, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack response = self.app(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return self.func(req, *args, **kwargs) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 906, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack content_type, body, accept) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 972, in _process_stack 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 1056, in dispatch 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return method(req=request, **action_args) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/compute/contrib/server_external_events.py", line 128, in create 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack accepted) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 3141, in external_instance_event 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack context, instances_by_host[host], events_by_host[host]) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 1025, in external_instance_event 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack server=_compute_host(None, instances[0]), 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 61, in _compute_host 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack 'Instance %s') % instance['uuid']) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack NovaException: Unable to find host for Instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack 2014-07-22 17:15:25.552 INFO nova.api.openstack [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] http://127.0.0.1:8774/v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events returned with HTTP 500 2014-07-22 17:15:25.552 DEBUG nova.api.openstack.wsgi [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /opt/stack/new/nova/nova/api/openstack/wsgi.py:1198 2014-07-22 17:15:25.553 INFO nova.osapi_compute.wsgi.server [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] 127.0.0.1 "POST /v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events HTTP/1.1" status: 500 len: 335 time: 0.0841761 The error on the q-svc side: http://logs.openstack.org/73/104673/6/check/check-tempest-dsvm-neutron-full/a1ee0ee/logs/screen-q-svc.txt.gz#_2014-07-22_17_15_25_578 2014-07-22 17:15:25.577 26518 DEBUG urllib3.connectionpool [-] "POST /v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events HTTP/1.1" 500 128 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:415 2014-07-22 17:15:25.578 26518 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'52f5dc11-1e59-48fe-867c-e059b5c652c6', 'name': 'network-vif-plugged', 'server_uuid': u'f918bf3f-2fca-45fe-bf3c-d52dd98b90b3'}] 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova Traceback (most recent call last): 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/neutron/neutron/notifiers/nova.py", line 223, in send_events 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova batched_events) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/v1_1/contrib/server_external_events.py", line 39, in create 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova return_raw=True) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/base.py", line 100, in _create 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 485, in post 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 459, in _cs_request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 441, in _time_request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova resp, body = self.request(url, method, **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 435, in request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova raise exceptions.from_response(resp, body, url, method) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova 2014-07-22 17:15:25.651 26518 INFO neutron.wsgi [-] (26518) accepted ('127.0.0.1', 58973) logstash query: message: "Caught error: Unable to find host for Instance" AND filename:"logs/screen-n-api.txt" http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOiBcIkNhdWdodCBlcnJvcjogVW5hYmxlIHRvIGZpbmQgaG9zdCBmb3IgSW5zdGFuY2VcIiAgQU5EIGZpbGVuYW1lOlwibG9ncy9zY3JlZW4tbi1hcGkudHh0XCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0MDYxMzU3NjY4MzIsIm1vZGUiOiIiLCJhbmFseXplX2ZpZWxkIjoiIn0= ** Affects: nova Importance: Undecided Status: New -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to OpenStack Compute (nova). https://bugs.launchpad.net/bugs/1347833 Title: os-server-external-events responses 500 to neutron Status in OpenStack Compute (Nova): New Bug description: The issue usually not fatal, but nova MUST not return 500 on these requests. http://logs.openstack.org/73/104673/6/check/check-tempest-dsvm-neutron-full/a1ee0ee/logs/screen-n-api.txt.gz#_2014-07-22_17_15_25_548 2014-07-22 17:15:25.547 AUDIT nova.api.openstack.compute.contrib.server_external_events [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Create event network-vif-plugged:52f5dc11-1e59-48fe-867c-e059b5c652c6 for instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 ERROR nova.api.openstack [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Caught error: Unable to find host for Instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack Traceback (most recent call last): 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 121, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return req.get_response(self.application) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack application, catch_exc_info=False) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack app_iter = application(self.environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 559, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return self._app(env, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack response = self.app(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return resp(environ, start_response) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return self.func(req, *args, **kwargs) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 906, in __call__ 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack content_type, body, accept) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 972, in _process_stack 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 1056, in dispatch 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack return method(req=request, **action_args) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/compute/contrib/server_external_events.py", line 128, in create 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack accepted) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 3141, in external_instance_event 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack context, instances_by_host[host], events_by_host[host]) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 1025, in external_instance_event 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack server=_compute_host(None, instances[0]), 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 61, in _compute_host 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack 'Instance %s') % instance['uuid']) 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack NovaException: Unable to find host for Instance f918bf3f-2fca-45fe-bf3c-d52dd98b90b3 2014-07-22 17:15:25.548 26476 TRACE nova.api.openstack 2014-07-22 17:15:25.552 INFO nova.api.openstack [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] http://127.0.0.1:8774/v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events returned with HTTP 500 2014-07-22 17:15:25.552 DEBUG nova.api.openstack.wsgi [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /opt/stack/new/nova/nova/api/openstack/wsgi.py:1198 2014-07-22 17:15:25.553 INFO nova.osapi_compute.wsgi.server [req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209 nova service] 127.0.0.1 "POST /v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events HTTP/1.1" status: 500 len: 335 time: 0.0841761 The error on the q-svc side: http://logs.openstack.org/73/104673/6/check/check-tempest-dsvm-neutron-full/a1ee0ee/logs/screen-q-svc.txt.gz#_2014-07-22_17_15_25_578 2014-07-22 17:15:25.577 26518 DEBUG urllib3.connectionpool [-] "POST /v2/d87904e2444e48bc9632f3087e45b14e/os-server-external-events HTTP/1.1" 500 128 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:415 2014-07-22 17:15:25.578 26518 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'52f5dc11-1e59-48fe-867c-e059b5c652c6', 'name': 'network-vif-plugged', 'server_uuid': u'f918bf3f-2fca-45fe-bf3c-d52dd98b90b3'}] 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova Traceback (most recent call last): 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/neutron/neutron/notifiers/nova.py", line 223, in send_events 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova batched_events) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/v1_1/contrib/server_external_events.py", line 39, in create 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova return_raw=True) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/base.py", line 100, in _create 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 485, in post 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 459, in _cs_request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 441, in _time_request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova resp, body = self.request(url, method, **kwargs) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova File "/opt/stack/new/python-novaclient/novaclient/client.py", line 435, in request 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova raise exceptions.from_response(resp, body, url, method) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-82b210ca-21a9-4b40-b26a-ff0a4b1a3209) 2014-07-22 17:15:25.578 26518 TRACE neutron.notifiers.nova 2014-07-22 17:15:25.651 26518 INFO neutron.wsgi [-] (26518) accepted ('127.0.0.1', 58973) logstash query: message: "Caught error: Unable to find host for Instance" AND filename:"logs/screen-n-api.txt" http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOiBcIkNhdWdodCBlcnJvcjogVW5hYmxlIHRvIGZpbmQgaG9zdCBmb3IgSW5zdGFuY2VcIiAgQU5EIGZpbGVuYW1lOlwibG9ncy9zY3JlZW4tbi1hcGkudHh0XCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0MDYxMzU3NjY4MzIsIm1vZGUiOiIiLCJhbmFseXplX2ZpZWxkIjoiIn0= To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1347833/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
