yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1764556] Re: "nova list" fails with exception.ServiceNotFound if service is deleted and has no UUID

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date: Wed, 18 Apr 2018 18:26:05 -0000
Reply-to: Bug 1764556 <1764556@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: New => Confirmed

** Changed in: nova
   Importance: Undecided => Medium

** Also affects: nova/pike
   Importance: Undecided
       Status: New

** Also affects: nova/queens
   Importance: Undecided
       Status: New

** Changed in: nova/pike
       Status: New => Confirmed

** Changed in: nova/queens
       Status: New => Confirmed

** Changed in: nova/pike
   Importance: Undecided => Medium

** Changed in: nova/queens
   Importance: Undecided => Medium

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

Title:
  "nova list" fails with exception.ServiceNotFound if service is deleted
  and has no UUID

Status in OpenStack Compute (nova):
  Confirmed
Status in OpenStack Compute (nova) pike series:
  Confirmed
Status in OpenStack Compute (nova) queens series:
  Confirmed

Bug description:
  We had a testcase where we booted an instance on Newton, migrated it
  off the compute node, deleted the compute node (and service), upgraded
  to Pike, created a new compute node with the same name, and migrated
  the instance back to the compute node.

  At this point the "nova list" command failed with
  exception.ServiceNotFound.

  It appears that since the Service has no UUID the _from_db_object()
  routine will try to add it, but the service.save() call fails because
  the service in question has been deleted.

  I reproduced the issue with stable/pike devstack.  I booted an
  instance, then created a fake entry in the "services" table without a
  UUID so the table looked like this:

  mysql>  select * from services;
  +---------------------+---------------------+---------------------+----+----------+----------------+-----------+--------------+----------+---------+-----------------+---------------------+-------------+---------+--------------------------------------+
  | created_at          | updated_at          | deleted_at          | id | host     | binary         | topic     | report_count | disabled | deleted | disabled_reason | last_seen_up        | forced_down | version | uuid                                 |
  +---------------------+---------------------+---------------------+----+----------+----------------+-----------+--------------+----------+---------+-----------------+---------------------+-------------+---------+--------------------------------------+
  | 2018-02-20 16:10:07 | 2018-04-16 22:10:46 | NULL                |  1 | devstack | nova-conductor | conductor |       477364 |        0 |       0 | NULL            | 2018-04-16 22:10:46 |           0 |      22 | c041d7cf-5047-4014-b50c-3ba6b5d95097 |
  | 2018-02-20 16:10:10 | 2018-04-16 22:10:54 | NULL                |  2 | devstack | nova-compute   | compute   |       477149 |        0 |       0 | NULL            | 2018-04-16 22:10:54 |           0 |      22 | d0cfb63c-8b59-4b65-bb7e-6b89acd3fe35 |
  | 2018-02-20 16:10:10 | 2018-04-16 20:29:33 | 2018-04-16 20:30:33 |  3 | devstack | nova-compute   | compute   |       476432 |        0 |       3 | NULL            | 2018-04-16 20:30:33 |           0 |      22 | NULL                                 |
  +---------------------+---------------------+---------------------+----+----------+----------------+-----------+--------------+----------+---------+-----------------+---------------------+-------------+---------+--------------------------------------+


  At this point, running "nova show <uuid>" worked fine, but running
  "nova list" failed:

  stack@devstack:~/devstack$ nova list
  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.ServiceNotFound'> (HTTP 500) (Request-ID: req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6)

  
  The nova-api log looked like this:

  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: DEBUG nova.compute.api [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Listing 1000 instances in cell 09eb515f-9906-40bf-9be6-63b5e6ee279a(cell1) {{(pid=4261) _get_instances_by_filters_all_cells /opt/stack/nova/nova/compute/api.py:2559}}
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: DEBUG oslo_concurrency.lockutils [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Lock "09eb515f-9906-40bf-9be6-63b5e6ee279a" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=4261) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270}}
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: DEBUG oslo_concurrency.lockutils [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Lock "09eb515f-9906-40bf-9be6-63b5e6ee279a" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=4261) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282}}
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: DEBUG nova.objects.service [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Generated UUID 4368a7ff-f589-4197-b0b9-d2afdb71ca33 for service 3 {{(pid=4261) _from_db_object /opt/stack/nova/nova/objects/service.py:245}}
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Unexpected exception in API method: ServiceNotFound: Service 3 could not be found.
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions Traceback (most recent call last):
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/openstack/extensions.py", line 336, in wrapped
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/validation/__init__.py", line 181, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/validation/__init__.py", line 181, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 168, in detail
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     servers = self._get_servers(req, is_detail=True)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 311, in _get_servers
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     sort_keys=sort_keys, sort_dirs=sort_dirs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 2468, in get_all
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     sort_dirs=sort_dirs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 2565, in _get_instances_by_filters_all_cells
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 2596, in _get_instances_by_filters
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     expected_attrs=fields, sort_keys=sort_keys, sort_dirs=sort_dirs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     result = fn(cls, context, *args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/objects/instance.py", line 1252, in get_by_filters
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     expected_attrs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/objects/instance.py", line 1199, in _make_instance_list
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     expected_attrs=expected_attrs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/objects/instance.py", line 448, in _from_db_object
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     objects.Service, db_inst['services'])
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 1121, in obj_make_list
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     **extra_args)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/objects/service.py", line 246, in _from_db_object
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     service.save()
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return fn(self, *args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/objects/service.py", line 363, in save
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     db_service = db.service_update(self._context, self.id, updates)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/db/api.py", line 189, in service_update
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return IMPL.service_update(context, service_id, values)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 150, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     ectxt.value = e.inner_exc
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     self.force_reraise()
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 250, in wrapped
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return f(context, *args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 610, in service_update
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     service_ref = service_get(context, service_id)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 265, in wrapped
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     return f(context, *args, **kwargs)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions   File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 472, in service_get
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions     raise exception.ServiceNotFound(service_id=service_id)
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions ServiceNotFound: Service 3 could not be found.
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: ERROR nova.api.openstack.extensions 
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: INFO nova.api.openstack.wsgi [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: <class 'nova.exception.ServiceNotFound'>
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: DEBUG nova.api.openstack.wsgi [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: <class 'nova.exception.ServiceNotFound'> {{(pid=4261) __call__ /opt/stack/nova/nova/api/openstack/wsgi.py:1029}}
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: INFO nova.api.openstack.requestlog [None req-b7e1b5f9-e7b4-4ccf-ba28-e8b3e1acd2f6 demo demo] 128.224.186.226 "GET /compute/v2.1/servers/detail" status: 500 len: 204 microversion: 2.53 time: 0.131473
  Apr 16 22:11:00 devstack devstack@n-api.service[4258]: [pid: 4261|app: 0|req: 6/12] 128.224.186.226 () {64 vars in 1290 bytes} [Mon Apr 16 22:11:00 2018] GET /compute/v2.1/servers/detail => generated 204 bytes in 132 msecs (HTTP/1.1 500) 9 headers in 393 bytes (1 switches on core 0)

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1764556/+subscriptions
References

[Bug 1764556] [NEW] "nova list" fails with exception.ServiceNotFound if service is deleted and has no UUID
From: Chris Friesen, 2018-04-16