yahoo-eng-team team mailing list archive

[Rajesh Tailor <rajesh.tailor@xxxxxxxxxxx>]

Public bug reported:

This is a timing issue and can occur if instance delete call reaches to
_delete_instance method in nova/compute/manager.py module and nova-
compute crashes after setting instance vm_state to 'DELETED' but before
destroying the instance in db.

Now on restarting nova-compute service, _init_instance method call
checks whether instance vm_state is 'DELETED' or not, if yes, then it
tries to call _complete_partial_deletion method and destroys instance in
db then raises "ValueError: Circular reference detected" and quota was
not updated for that instance which is not as expected.

Steps to reproduce:
1) Put a break point in nova/compute/manager.py module in _delete_instance method, just after updating instance vm_state to 'DELETED' but before destroying instance in db.
2) Create instance and wait until instance vm_state become 'ACTIVE'.
$ nova boot --image <image_id> --flavor <flavor_id> <name>

3) Send request to delete instance.
$ nova delete <instance_id>

4) When delete request reaches to break point in nova-compute, make sure instance vm_state is marked as 'DELETED' and stop the nova-compute service.
5) Restart nova-compute service and in _init_instance method call below error (ValueError: Circular reference detected) will be raised and instance will be marked as deleted in db but quota for that instance will never be updated.

2015-09-08 00:36:34.133 ERROR nova.compute.manager [req-3222b8a4-0542-48cf-a2e1-c92e5fd91e5e None None] [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] Failed to complete a deletion
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] Traceback (most recent call last):
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/compute/manager.py", line 952, in _init_instance
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     self._complete_partial_deletion(context, instance)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/compute/manager.py", line 879, in _complete_partial_d
eletion
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     bdms = objects.BlockDeviceMappingList.get_by_instance_uuid(
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", lin
e 197, in wrapper
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     ctxt, self, fn.__name__, args, kwargs)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 246, in object_action
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     objmethod=objmethod, args=args, kwargs=kwargs)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     retry=self.retry)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     timeout=timeout, retry=retry)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     retry=retry)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 399, in _send
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     msg = rpc_common.serialize_msg(msg)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/common.py", line 286, in serialize_msg
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     _MESSAGE_KEY: jsonutils.dumps(raw_msg)}
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_serialization/jsonutils.py", line 185, in dumps
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     return json.dumps(obj, default=default, **kwargs)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/__init__.py", line 250, in dumps
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     sort_keys=sort_keys, **kw).encode(obj)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/encoder.py", line 207, in encode
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     chunks = self.iterencode(o, _one_shot=True)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/encoder.py", line 270, in iterencode
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     return _iterencode(o, 0)
2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] ValueError: Circular reference detected

** Affects: nova
     Importance: Undecided
     Assignee: Rajesh Tailor (rajesh-tailor)
         Status: New

** Changed in: nova
     Assignee: (unassigned) => Rajesh Tailor (rajesh-tailor)

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

Title:
  On compute restart, quotas are not updated when instance vm_state is
  'DELETED' but instance is not destroyed in db

Status in OpenStack Compute (nova):
  New

Bug description:
  This is a timing issue and can occur if instance delete call reaches
  to _delete_instance method in nova/compute/manager.py module and nova-
  compute crashes after setting instance vm_state to 'DELETED' but
  before destroying the instance in db.

  Now on restarting nova-compute service, _init_instance method call
  checks whether instance vm_state is 'DELETED' or not, if yes, then it
  tries to call _complete_partial_deletion method and destroys instance
  in db then raises "ValueError: Circular reference detected" and quota
  was not updated for that instance which is not as expected.

  Steps to reproduce:
  1) Put a break point in nova/compute/manager.py module in _delete_instance method, just after updating instance vm_state to 'DELETED' but before destroying instance in db.
  2) Create instance and wait until instance vm_state become 'ACTIVE'.
  $ nova boot --image <image_id> --flavor <flavor_id> <name>

  3) Send request to delete instance.
  $ nova delete <instance_id>

  4) When delete request reaches to break point in nova-compute, make sure instance vm_state is marked as 'DELETED' and stop the nova-compute service.
  5) Restart nova-compute service and in _init_instance method call below error (ValueError: Circular reference detected) will be raised and instance will be marked as deleted in db but quota for that instance will never be updated.

  2015-09-08 00:36:34.133 ERROR nova.compute.manager [req-3222b8a4-0542-48cf-a2e1-c92e5fd91e5e None None] [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] Failed to complete a deletion
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] Traceback (most recent call last):
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/compute/manager.py", line 952, in _init_instance
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     self._complete_partial_deletion(context, instance)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/compute/manager.py", line 879, in _complete_partial_d
  eletion
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     bdms = objects.BlockDeviceMappingList.get_by_instance_uuid(
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", lin
  e 197, in wrapper
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     ctxt, self, fn.__name__, args, kwargs)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 246, in object_action
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     objmethod=objmethod, args=args, kwargs=kwargs)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     retry=self.retry)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     timeout=timeout, retry=retry)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     retry=retry)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 399, in _send
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     msg = rpc_common.serialize_msg(msg)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/common.py", line 286, in serialize_msg
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     _MESSAGE_KEY: jsonutils.dumps(raw_msg)}
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/local/lib/python2.7/dist-packages/oslo_serialization/jsonutils.py", line 185, in dumps
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     return json.dumps(obj, default=default, **kwargs)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/__init__.py", line 250, in dumps
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     sort_keys=sort_keys, **kw).encode(obj)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/encoder.py", line 207, in encode
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     chunks = self.iterencode(o, _one_shot=True)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]   File "/usr/lib/python2.7/json/encoder.py", line 270, in iterencode
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536]     return _iterencode(o, 0)
  2015-09-08 00:36:34.133 TRACE nova.compute.manager [instance: 00c7a9ae-bff1-461f-ab95-0e8f15327536] ValueError: Circular reference detected

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