yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1462128] Re: Cells: DBReferenceError possible deleting unscheduled instance

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Thu, 24 Sep 2015 18:48:58 -0000
Reply-to: Bug 1462128 <1462128@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Also affects: nova/kilo
   Importance: Undecided
       Status: New

** Changed in: nova/kilo
       Status: New => In Progress

** Changed in: nova/kilo
     Assignee: (unassigned) => Matt Riedemann (mriedem)

** Changed in: nova/kilo
   Importance: Undecided => Low

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

Title:
  Cells: DBReferenceError possible deleting unscheduled instance

Status in OpenStack Compute (nova):
  Fix Released
Status in OpenStack Compute (nova) kilo series:
  In Progress

Bug description:
  In cells, when a delete request comes in before an instance has been
  scheduled, cells will broadcast a "delete everywhere" to delete the
  instance in all cells. During the delete code path in compute,
  instance.save() attempts to save some state along the way before
  instance.destroy(). If there isn't an instance record in the child
  database, the FK constraint to save state (for example, flavor), will
  fail and DBReference error will be raised by oslo.db. In cells,
  InstanceNotFound is caught and handled for these scenarios. Since a FK
  constraint failure does mean the instance doesn't exist, it would make
  sense to raise InstanceNotFound for DBReferenceError.

  Logstash query:

  message:"DBReferenceError" AND build_name:"check-tempest-dsvm-cells"

  Example trace:

  http://logs.openstack.org/49/188249/2/check/check-tempest-dsvm-
  cells/a74468a/logs/screen-n-cell-child.txt.gz#_2015-06-04_07_22_45_806

  2015-06-04 07:22:45.806 ERROR nova.cells.messaging [req-388635a4-8e75-4986-af34-99e6eca82f3b ServersNegativeTestJSON-34383368 ServersNegativeTestJSON-350156579] Error processing message locally
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging Traceback (most recent call last):
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 201, in _process_locally
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     resp_value = self.msg_runner._process_message_locally(self)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 1277, in _process_message_locally
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return fn(message, **message.method_kwargs)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 1090, in instance_delete_everywhere
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     self.compute_api.delete(message.ctxt, instance)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 227, in wrapped
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return func(self, context, target, *args, **kwargs)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 216, in inner
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return function(self, context, instance, *args, **kwargs)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 244, in _wrapped
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return fn(self, context, instance, *args, **kwargs)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 197, in inner
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return f(self, context, instance, *args, **kw)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 1820, in delete
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     self._delete_instance(context, instance)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 1810, in _delete_instance
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     task_state=task_states.DELETING)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 1622, in _delete
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     quotas.rollback()
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 119, in __exit__
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     six.reraise(self.type_, self.value, self.tb)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 1538, in _delete
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     instance.save()
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/objects/base.py", line 205, in wrapper
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return fn(self, *args, **kwargs)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/objects/instance.py", line 826, in save
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     getattr(self, '_save_%s' % field)(context)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/objects/instance.py", line 716, in _save_flavor
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     {'flavor': jsonutils.dumps(flavor_info)})
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/db/api.py", line 919, in instance_extra_update_by_uuid
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     updates)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2643, in instance_extra_update_by_uuid
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     _instance_extra_create(context, create_values)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2631, in _instance_extra_create
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     inst_extra_ref.save()
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/db/sqlalchemy/models.py", line 82, in save
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     super(NovaBase, self).save(session=session)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/models.py", line 48, in save
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     session.flush()
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1985, in flush
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     self._flush(objects)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2103, in _flush
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     transaction.rollback(_capture_exception=True)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     compat.reraise(exc_type, exc_value, exc_tb)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2067, in _flush
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     flush_context.execute()
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     rec.execute(self)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     uow
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     mapper, table, insert)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 602, in _emit_insert_statements
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     execute(statement, params)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 841, in execute
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return meth(self, multiparams, params)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     return connection._execute_clauseelement(self, multiparams, params)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 938, in _execute_clauseelement
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     compiled_sql, distilled_params
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1070, in _execute_context
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     context)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/compat/handle_error.py", line 155, in _handle_dbapi_exception
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     e, statement, parameters, cursor, context)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1267, in _handle_dbapi_exception
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     util.raise_from_cause(newraise, exc_info)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     reraise(type(exception), exception, tb=exc_tb)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1063, in _execute_context
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     context)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 442, in do_execute
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     cursor.execute(statement, parameters)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     self.errorhandler(self, exc, value)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging   File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging     raise errorclass, errorvalue
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging DBReferenceError: (IntegrityError) (1452, 'Cannot add or update a child row: a foreign key constraint fails (`nova_cell`.`instance_extra`, CONSTRAINT `instance_extra_instance_uuid_fkey` FOREIGN KEY (`instance_uuid`) REFERENCES `instances` (`uuid`))') 'INSERT INTO instance_extra (created_at, updated_at, deleted_at, deleted, instance_uuid, numa_topology, pci_requests, flavor, vcpu_model) VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s)' (datetime.datetime(2015, 6, 4, 7, 22, 45, 797823), None, None, 0, '29f21049-ae1d-492f-a7f4-616b57abc755', None, None, '{"new": null, "old": null, "cur": {"nova_object.version": "1.1", "nova_object.name": "Flavor", "nova_object.data": {"disabled": false, "root_gb": 0, "name": "m1.nano", "flavorid": "42", "deleted": false, "created_at": "2015-06-04T07:19:00Z", "ephemeral_gb": 0, "updated_at": null, "memory_mb": 64, "vcpus": 1, "extra_specs": {}, "swap": 0, "rxtx_factor": 1.0, "is_public": true, "deleted_at": null, "vcpu_weight": 0, "id": 6}, "nova_object.namespace": "nova"}}', None)
  2015-06-04 07:22:45.806 16038 ERROR nova.cells.messaging

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

[Bug 1462128] [NEW] Cells: DBReferenceError possible deleting unscheduled instance
From: melanie witt, 2015-06-04