← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #59937

[Bug 1651319] [NEW] "nova list --delete" failed due to InstanceNotFound exception

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

Description
===========
When I run "nova list --delete" on our OpenStack environment(Mitaka(RHOSP9)), it failed due to the following error.
------------
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.InstanceNotFound'> (HTTP 500) (Request-ID: req-f2ee67f2-2d81-4e6f-b707-d9a713383191)
------------

   Note: I reproduced it on our Newton(RHOSP10) environment too.

And the following messages was outputted from nova-api.log.
-----------------------------
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions [req-f2ee67f2-2d81-4e6f-b707-d9a713383191 48c0c48c3a284a909b5dd6aa20073ffa ebb9a4f3d9d845bdb984c18c1d8fae05 - - -] Unexpected exception in API method
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/extensions.py", line 478, in wrapped
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 294, in detail
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     servers = self._get_servers(req, is_detail=True)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 421, in _get_servers
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     response = self._view_builder.detail(req, instance_list)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 150, in detail
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return self._list_view(self.show, request, instances, coll_name)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 162, in _list_view
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     server_list = [func(request, server)["server"] for server in servers]
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 290, in show
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     "flavor": self._get_flavor(request, instance),
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 222, in _get_flavor
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     instance_type = instance.get_flavor()
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 932, in get_flavor
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return getattr(self, attr)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 67, in getter
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     self.obj_load_attr(name)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 917, in obj_load_attr
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     self._load_flavor()
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 793, in _load_flavor
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     expected_attrs=['flavor', 'system_metadata'])
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 181, in wrapper
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     result = fn(cls, context, *args, **kwargs)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 399, in get_by_uuid
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     use_slave=use_slave)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 285, in wrapper
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 391, in _db_instance_get_by_uuid
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     columns_to_join=columns_to_join)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 696, in instance_get_by_uuid
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return IMPL.instance_get_by_uuid(context, uuid, columns_to_join)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 229, in wrapper
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 330, in wrapped
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(context, *args, **kwargs)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1970, in instance_get_by_uuid
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     columns_to_join=columns_to_join)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1979, in _instance_get_by_uuid
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     raise exception.InstanceNotFound(instance_id=uuid)
2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions InstanceNotFound: Instance decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e could not be found.
-----------------------------

I noticed that when this problem happened, there were 2 records about the
instance(decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6) that caused the error in 
instance_extra table of nova DB. And one of their flavor is NULL.

--------
# mysql -u root nova -e "select * from instance_extra where instance_uuid='decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e'\G" 
*************************** 1. row ***************************
        created_at: 2016-11-16 07:25:09
        updated_at: 2016-11-16 07:27:24
        deleted_at: 2016-11-16 07:27:26
           deleted: 5837
                id: 5837
     instance_uuid: decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e
     numa_topology: NULL
      pci_requests: []
            flavor: {"new": null, "old": null, "cur": {"nova_object.version": "1.1", ....
            .....
*************************** 2. row ***************************
        created_at: 2016-11-16 07:27:26
        updated_at: NULL
        deleted_at: NULL
           deleted: 0
                id: 5838
     instance_uuid: decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e
     numa_topology: NULL
      pci_requests: []
            flavor: NULL
            .....
--------

According to my investigating, in the current instance_extra_update_by_uuid(), 
when updating an instance, if there is no entry for an instance, nova create 
a new entry for it. For somehow, if updating comes after the instance has been deleted 
(its entry would be soft-deleted), nova would create a new entry for 
the deleted instance and keep its flavor being NULL. It causes instance_extra 
entry duplicate for the same instance_uuid. I think it cause this problem.

Steps to reproduce
==================
I can reproduce the problem with the following steps.

   Note: please notice it's timing problem. It doesn't alway heppen.
         But once it happened, it can be reproduced always.
         Unless you delete the duplicate entry from instance_extra table.

1, Boot an instance. Meanwhile stop rabbitmq-server.
2, Restart rabbitmq-server.
3, Delete the instance.
4, Run "nova list --delete".

For those deleted instance, I think we shouldn't 
create a new entry for it. It's better to just skip the "updating".

** Affects: nova
     Importance: Undecided
     Assignee: wei-fan@xxxxxxxxxxxxx (wei-fan)
         Status: New


** Tags: db

** Changed in: nova
     Assignee: (unassigned) => wei-fan@xxxxxxxxxxxxx (wei-fan)

-- 
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/1651319

Title:
  "nova list --delete" failed due to InstanceNotFound exception

Status in OpenStack Compute (nova):
  New

Bug description:
  Description
  ===========
  When I run "nova list --delete" on our OpenStack environment(Mitaka(RHOSP9)), it failed due to the following error.
  ------------
  ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'nova.exception.InstanceNotFound'> (HTTP 500) (Request-ID: req-f2ee67f2-2d81-4e6f-b707-d9a713383191)
  ------------

     Note: I reproduced it on our Newton(RHOSP10) environment too.

  And the following messages was outputted from nova-api.log.
  -----------------------------
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions [req-f2ee67f2-2d81-4e6f-b707-d9a713383191 48c0c48c3a284a909b5dd6aa20073ffa ebb9a4f3d9d845bdb984c18c1d8fae05 - - -] Unexpected exception in API method
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/extensions.py", line 478, in wrapped
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 294, in detail
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     servers = self._get_servers(req, is_detail=True)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 421, in _get_servers
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     response = self._view_builder.detail(req, instance_list)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 150, in detail
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return self._list_view(self.show, request, instances, coll_name)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 162, in _list_view
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     server_list = [func(request, server)["server"] for server in servers]
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 290, in show
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     "flavor": self._get_flavor(request, instance),
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/views/servers.py", line 222, in _get_flavor
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     instance_type = instance.get_flavor()
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 932, in get_flavor
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return getattr(self, attr)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 67, in getter
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     self.obj_load_attr(name)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 917, in obj_load_attr
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     self._load_flavor()
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 793, in _load_flavor
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     expected_attrs=['flavor', 'system_metadata'])
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 181, in wrapper
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     result = fn(cls, context, *args, **kwargs)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 399, in get_by_uuid
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     use_slave=use_slave)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 285, in wrapper
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 391, in _db_instance_get_by_uuid
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     columns_to_join=columns_to_join)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 696, in instance_get_by_uuid
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return IMPL.instance_get_by_uuid(context, uuid, columns_to_join)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 229, in wrapper
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 330, in wrapped
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     return f(context, *args, **kwargs)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1970, in instance_get_by_uuid
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     columns_to_join=columns_to_join)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1979, in _instance_get_by_uuid
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions     raise exception.InstanceNotFound(instance_id=uuid)
  2016-11-25 11:22:25.660 21809 ERROR nova.api.openstack.extensions InstanceNotFound: Instance decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e could not be found.
  -----------------------------

  I noticed that when this problem happened, there were 2 records about the
  instance(decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6) that caused the error in 
  instance_extra table of nova DB. And one of their flavor is NULL.

  --------
  # mysql -u root nova -e "select * from instance_extra where instance_uuid='decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e'\G" 
  *************************** 1. row ***************************
          created_at: 2016-11-16 07:25:09
          updated_at: 2016-11-16 07:27:24
          deleted_at: 2016-11-16 07:27:26
             deleted: 5837
                  id: 5837
       instance_uuid: decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e
       numa_topology: NULL
        pci_requests: []
              flavor: {"new": null, "old": null, "cur": {"nova_object.version": "1.1", ....
              .....
  *************************** 2. row ***************************
          created_at: 2016-11-16 07:27:26
          updated_at: NULL
          deleted_at: NULL
             deleted: 0
                  id: 5838
       instance_uuid: decfb2f4-d8a6-49dd-89f0-3aa2fdeb8b6e
       numa_topology: NULL
        pci_requests: []
              flavor: NULL
              .....
  --------

  According to my investigating, in the current instance_extra_update_by_uuid(), 
  when updating an instance, if there is no entry for an instance, nova create 
  a new entry for it. For somehow, if updating comes after the instance has been deleted 
  (its entry would be soft-deleted), nova would create a new entry for 
  the deleted instance and keep its flavor being NULL. It causes instance_extra 
  entry duplicate for the same instance_uuid. I think it cause this problem.

  Steps to reproduce
  ==================
  I can reproduce the problem with the following steps.

     Note: please notice it's timing problem. It doesn't alway heppen.
           But once it happened, it can be reproduced always.
           Unless you delete the duplicate entry from instance_extra table.

  1, Boot an instance. Meanwhile stop rabbitmq-server.
  2, Restart rabbitmq-server.
  3, Delete the instance.
  4, Run "nova list --delete".

  For those deleted instance, I think we shouldn't 
  create a new entry for it. It's better to just skip the "updating".

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1651319/+subscriptions
  Thread Previous • Date Previous • • Thread Next