nova list can sometimes return 404

Bug #1610153 reported by Oleg Bondarev
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Confirmed
Undecided
Unassigned

Bug Description

On a large number of instances 'nova list' may return 404, probably this is because some instances are deleted during command execution. Trace:

2016-08-05 09:30:52.666 878 ERROR nova.api.openstack [req-707a0e40-67cf-43a9-865d-c44a678b2986 2e2a43e956f344d184e40771d59c991d 13f508a4dd0e4b538561be2afcf5d699 - - -] Caught error: Instance 28c33ed4-c1a4-432c-96de-059b94a3dd91 could not be found.
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack Traceback (most recent call last):
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/api/openstack/__init__.py", line 139, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return req.get_response(self.application)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack application, catch_exc_info=False)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack app_iter = application(self.environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return resp(environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return self.func(req, *args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py", line 467, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack response = req.get_response(self._app)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack application, catch_exc_info=False)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack app_iter = application(self.environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return resp(environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return resp(environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 136, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack response = self.app(environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return resp(environ, start_response)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return self.func(req, *args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 672, in __call__
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack content_type, body, accept)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 756, in _process_stack
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack request, action_args)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 619, in post_process_extensions
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack **action_args)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/extended_server_attributes.py", line 97, in detail
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack instances.values())
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3597, in get_instances_host_statuses
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack host_status = self.get_instance_host_status(instance)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 3575, in get_instance_host_status
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack service = [service for service in instance.services if
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 67, in getter
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack self.obj_load_attr(name)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 925, in obj_load_attr
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack self._load_generic(attrname)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 753, in _load_generic
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack expected_attrs=[attrname])
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 181, in wrapper
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack result = fn(cls, context, *args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 399, in get_by_uuid
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack use_slave=use_slave)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 285, in wrapper
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return f(*args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 391, in _db_instance_get_by_uuid
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack columns_to_join=columns_to_join)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 696, in instance_get_by_uuid
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return IMPL.instance_get_by_uuid(context, uuid, columns_to_join)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 229, in wrapper
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return f(*args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 330, in wrapped
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack return f(context, *args, **kwargs)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 1967, in instance_get_by_uuid
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack columns_to_join=columns_to_join)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 1976, in _instance_get_by_uuid
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack raise exception.InstanceNotFound(instance_id=uuid)
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack InstanceNotFound: Instance 28c33ed4-c1a4-432c-96de-059b94a3dd91 could not be found.
2016-08-05 09:30:52.666 878 ERROR nova.api.openstack
2016-08-05 09:30:52.672 878 INFO nova.api.openstack [req-707a0e40-67cf-43a9-865d-c44a678b2986 2e2a43e956f344d184e40771d59c991d 13f508a4dd0e4b538561be2afcf5d699 - - -] http://192.168.0.2:8774/v2.1/servers/detail?all_tenants=1 returned with HTTP 404
2016-08-05 09:30:52.679 878 INFO nova.osapi_compute.wsgi.server [req-707a0e40-67cf-43a9-865d-c44a678b2986 2e2a43e956f344d184e40771d59c991d 13f508a4dd0e4b538561be2afcf5d699 - - -] 192.168.0.2 "GET /v2.1/servers/detail?all_tenants=1 HTTP/1.1" status: 404 len: 363 time: 7.7833738

Andrey Volkov (avolkov)
Changed in nova:
status: New → Confirmed
Revision history for this message
Andrey Volkov (avolkov) wrote :

The bug is reproduced in upstream.
Steps to reproduce:
- Add sleep or pdb trace after instance loading.
  e.g. on the line
  https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2053.
- update some instance status: update instances set deleted = 1 where id = ...
- continue

It's non-repeatable reads kind of problem.
Possible solutions:
- Load all instance related data at once.
- Use transaction with Repeatable Read isolation level.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to nova (master)

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

commit d995e2eb9614cbe9a4b7d541cfd38da1b9daf4ee
Author: Andrey Volkov <email address hidden>
Date: Wed Aug 10 11:37:04 2016 +0300

    Tests: use fakes.HTTPRequest in compute tests

    In wsgi controllers tests fakes.HTTPRequest and webob.Request are used.
    fakes.HTTPRequest is the descendant of webob.Request defined in nova
    test codebase. To have single point of modification it's better to have
    common class for controllers tests.

    This change replaces webob.Request to fakes.HTTPRequest and updates
    blank method signature with respect to actual webob.Request.blank
    method.

    Change-Id: I043b9cf4426ec1d2c9b178a6ceacb74fc113e21b
    Related-Bug: #1610153

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Andrey Volkov (<email address hidden>) on branch: master
Review: https://review.openstack.org/352950

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to nova (master)

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

commit 7a391e400214aeb0c0bba430df8b651f0ea9cf83
Author: Andrey Volkov <email address hidden>
Date: Mon Aug 15 18:59:54 2016 +0300

    Eliminate additional DB queries in nova lists

    Servers detail call has the extension which adds additional attribute
    host_status to the instance (server). This extension mechanism issues a DB
    query for each instance.host which can be an overhead for installation
    with the large number of hosts. This change eliminates additional queries
    and replaces them with a join query.

    Before this change, it was K + N queries to DB
    where K is a number of queries to get instances list and N is a number of
    queries to get services for each instance.host.
    After this change, it's only K queries.

    Change-Id: Ia9331a2385b448c26ca7e281674a26f43e3f44de
    Related-Bug: #1610153

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Michael Still (<email address hidden>) on branch: master
Review: https://review.openstack.org/352950
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.

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.