nova list error when cloud has many instances and some instances is deleting.

[Charlotte Han]

1. Openstack cloud has many instances.

2. I delete some instances. At the same time, I execuate 'nova list'.

3. 2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return resp(environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 634, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return self._call_app(env, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 554, in _call_app
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return self._app(env, _fake_start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return resp(environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return resp(environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack response = self.app(environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return resp(environ, start_response)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 756, in __call__
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack content_type, body, accept)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 847, in _process_stack
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack request, action_args)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 710, in post_process_extensions
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack **action_args)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/contrib/extended_server_attributes.py", line 78, in detail
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack instances.values())
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 4230, in get_instances_host_statuses
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack host_status = self.get_instance_host_status(instance)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 4210, in get_instance_host_status
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack service = [service for service in instance.services if
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 72, in getter
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack self.obj_load_attr(name)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 1164, in obj_load_attr
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack self._load_generic(attrname)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 965, in _load_generic
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack expected_attrs=[attrname])
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 163, in wrapper
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack result = fn(cls, context, *args, **kwargs)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 587, in get_by_uuid
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack use_slave=use_slave)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 651, in instance_get_by_uuid
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack columns_to_join, use_slave=use_slave)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 233, in wrapper
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack return f(*args, **kwargs)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1748, in instance_get_by_uuid
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack columns_to_join=columns_to_join, use_slave=use_slave)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1760, in _instance_get_by_uuid
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack raise exception.InstanceNotFound(instance_id=uuid)
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack InstanceNotFound: Instance 1fa5f1fa-6b68-45a5-bbf3-793b6d48a587 could not be found.
2017-03-21 10:19:23.248 3713 TRACE nova.api.openstack
2017-03-21 10:19:23.252 3713 INFO nova.api.openstack [req-9dadd37d-16ce-4e00-843a-1d2baa5403d4 26bf7b2f5d7440f2a430888e4c2a7439 be858ad995d14a90b6521a5caef6230a - - -] http://10.128.104.70:8774/v2/be858ad995d14a90b6521a5caef6230a/servers/detail?all_tenants=1 returned with HTTP 404
2017-03-21 10:19:23.263 3713 INFO nova.osapi_compute.wsgi.server [req-9dadd37d-16ce-4e00-843a-1d2baa5403d4 26bf7b2f5d7440f2a430888e4c2a7439 be858ad995d14a90b6521a5caef6230a - - -] 192.168.33.5 "GET /v2/be858ad995d14a90b6521a5caef6230a/servers/detail?all_tenants=1 HTTP/1.0" status: 404 len: 291 time: 2.6909790
2017-03-21 10:19:23.346 3714 INFO nova.osapi_compute.wsgi.server [req-db29d6b8-492e-43c0-b4ea-ff8a9f968907 d28b50c0328247ccb8f3c68d8029f42a be858ad995d14a90b6521a5caef6230a - - -] 192.168.33.5 "GET /v2/be858ad995d14a90b6521a5caef6230a/servers/2190afd8-b010-477e-9ff0-68d62081a5df/os-interface HTTP/1.1" status: 200 len: 459 time: 0.0923660
2017-03-21 10:19:23.717 3714 INFO nova.osapi_compute.wsgi.server [req-40865d34-3f67-4278-8411-a323d1f1fcc8 d28b50c0328247ccb8f3c68d8029f42a be858ad995d14a90b6521a5caef6230a - - -] 192.168.33.5 "GET /v2/be858ad995d14a90b6521a5caef6230a/servers/fd25e4e7-22b9-4d91-a20a-3bc0185a6ab7/os-interface HTTP/1.1" status: 200 len: 1238 time: 0.1860509
2017-03-21 10:19:23.812 3715 ERROR nova.api.openstack [req-9295ea8d-7fbf-474c-a429-a35ee1144fc8 26bf7b2f5d7440f2a430888e4c2a7439 be858ad995d14a90b6521a5caef6230a - - -] Caught error: Instance 1fa5f1fa-6b68-45a5-bbf3-793b6d48a587 could not be found.

4. I think the instance in cache is not deleted, but when get instance'services, instance is deleted.

Database changed
MariaDB [nova]> select * from instances where uuid="1fa5f1fa-6b68-45a5-bbf3-793b6d48a587";
+---------------------+---------------------+---------------------+------+-------------+----------------------------------+----------------------------------+-----------+-----------+------------+--------------+----------+----------+-------------+----------+-----------+-------+---------------+-----------------+-----------+----------------+--------------+---------------------+---------------------+---------------+---------------------+-------------------+--------+---------+-----------------+------------------+---------+--------------------------------------+--------------+------------------+--------------+--------------+--------------+------------+--------------------------+---------------------+----------+------------------+--------------------+-------------------+---------+--------------+-----------+-----------------+---------+-----------+---------+--------------------+
| created_at | updated_at | deleted_at | id | internal_id | user_id | project_id | image_ref | kernel_id | ramdisk_id | launch_index | key_name | key_data | power_state | vm_state | memory_mb | vcpus | hostname | host | user_data | reservation_id | scheduled_at | launched_at | terminated_at | display_name | display_description | availability_zone | locked | os_type | launched_on | instance_type_id | vm_mode | uuid | architecture | root_device_name | access_ip_v4 | access_ip_v6 | config_drive | task_state | default_ephemeral_device | default_swap_device | progress | auto_disk_config | shutdown_terminate | disable_terminate | root_gb | ephemeral_gb | cell_name | node | deleted | locked_by | cleaned | ephemeral_key_uuid |
+---------------------+---------------------+---------------------+------+-------------+----------------------------------+----------------------------------+-----------+-----------+------------+--------------+----------+----------+-------------+----------+-----------+-------+---------------+-----------------+-----------+----------------+--------------+---------------------+---------------------+---------------+---------------------+-------------------+--------+---------+-----------------+------------------+---------+--------------------------------------+--------------+------------------+--------------+--------------+--------------+------------+--------------------------+---------------------+----------+------------------+--------------------+-------------------+---------+--------------+-----------+-----------------+---------+-----------+---------+--------------------+
| 2017-03-17 14:16:55 | 2017-03-21 07:19:31 | 2017-03-21 07:19:22 | 2947 | NULL | 26bf7b2f5d7440f2a430888e4c2a7439 | 95b0a270a1ad4ff0912e6b674a9e2abb | | | | 0 | NULL | NULL | 4 | deleted | 16384 | 8 | sinforvac-1-1 | DC2Computer0409 | NULL | r-36gs7b0c | NULL | 2017-03-17 14:17:15 | 2017-03-21 07:19:22 | sinforvac_1_1 | sinforvac_1_1 | NULL | 0 | NULL | DC2Computer0409 | 238 | NULL | 1fa5f1fa-6b68-45a5-bbf3-793b6d48a587 | NULL | /dev/vda | NULL | NULL | True | NULL | NULL | NULL | 0 | 0 | 0 | 0 | 0 | 0 | NULL | DC2Computer0409 | 2947 | NULL | 1 | NULL |
+---------------------+---------------------+---------------------+------+-------------+----------------------------------+----------------------------------+-----------+-----------+------------+--------------+----------+----------+-------------+----------+-----------+-------+---------------+-----------------+-----------+----------------+--------------+---------------------+---------------------+---------------+---------------------+-------------------+--------+---------+-----------------+------------------+---------+--------------------------------------+--------------+------------------+--------------+--------------+--------------+------------+--------------------------+---------------------+----------+------------------+--------------------+-------------------+---------+--------------+-----------+-----------------+---------+-----------+---------+--------------------+
1 row in set (0.00 sec)

[Sean Dague (sdague)]

Can you specify versions of openstack here, and if this is replicatable in master?

[Launchpad Janitor (janitor)]

[Expired for OpenStack Compute (nova) because there has been no activity for 60 days.]