yahoo-eng-team team mailing list archive

[melanie witt <1466696@xxxxxxxxxxxxxxxxxx>]

Public bug reported:

Observed in the tempest-dsvm-cells job during
tempest.api.compute.servers.test_server_actions.ServerActionsTestJSON.test_lock_unlock_server

The test locks an instance, attempts to stop it, makes sure that fails,
unlocks it, attempts to stop it, and makes sure that succeeds.

The problem happens during the succession of actions "unlock" and
"stop". The "unlock" does an instance.save() of the locked state at the
top cell which will sync to the child. If the "stop" request reaches the
child cell before the instance.save() state locked = False syncs to the
child cell, the "stop" will fail with the following trace in screen-n
-cell-child.txt:

2015-06-18 19:09:23.852 ERROR nova.cells.messaging [req-6b3584bb-b52a-41ba-8e88-000e14ba6ec6 ServerActionsTestJSON-1466672685 ServerActionsTestJSON-639331338] Error processing message locally
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging Traceback (most recent call last):
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 200, in _process_locally
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     resp_value = self.msg_runner._process_message_locally(self)
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 1256, in _process_message_locally
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     return fn(message, **message.method_kwargs)
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 850, in stop_instance
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     clean_shutdown=clean_shutdown)
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 839, in _call_compute_api_with_obj
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     return fn(ctxt, instance, *args, **kwargs)
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 214, in inner
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     raise exception.InstanceIsLocked(instance_uuid=instance.uuid)
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging InstanceIsLocked: Instance cb2485ba-e3e5-4668-869b-f145e5f28a1a is locked
2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging

Logstash query: message:"InstanceIsLocked" AND tags:"screen-n-cell-
child.txt"

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiSW5zdGFuY2VJc0xvY2tlZFwiIEFORCB0YWdzOlwic2NyZWVuLW4tY2VsbC1jaGlsZC50eHRcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQzNDY3NDMyOTQ0Mn0=

** Affects: nova
     Importance: Low
         Status: Confirmed


** Tags: cells

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

Title:
  Cells: Race between instance 'unlock' and 'stop' can cause 'stop' to
  fail

Status in OpenStack Compute (Nova):
  Confirmed

Bug description:
  Observed in the tempest-dsvm-cells job during
  tempest.api.compute.servers.test_server_actions.ServerActionsTestJSON.test_lock_unlock_server

  The test locks an instance, attempts to stop it, makes sure that
  fails, unlocks it, attempts to stop it, and makes sure that succeeds.

  The problem happens during the succession of actions "unlock" and
  "stop". The "unlock" does an instance.save() of the locked state at
  the top cell which will sync to the child. If the "stop" request
  reaches the child cell before the instance.save() state locked = False
  syncs to the child cell, the "stop" will fail with the following trace
  in screen-n-cell-child.txt:

  2015-06-18 19:09:23.852 ERROR nova.cells.messaging [req-6b3584bb-b52a-41ba-8e88-000e14ba6ec6 ServerActionsTestJSON-1466672685 ServerActionsTestJSON-639331338] Error processing message locally
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging Traceback (most recent call last):
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 200, in _process_locally
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     resp_value = self.msg_runner._process_message_locally(self)
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 1256, in _process_message_locally
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     return fn(message, **message.method_kwargs)
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 850, in stop_instance
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     clean_shutdown=clean_shutdown)
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/cells/messaging.py", line 839, in _call_compute_api_with_obj
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     return fn(ctxt, instance, *args, **kwargs)
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging   File "/opt/stack/new/nova/nova/compute/api.py", line 214, in inner
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging     raise exception.InstanceIsLocked(instance_uuid=instance.uuid)
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging InstanceIsLocked: Instance cb2485ba-e3e5-4668-869b-f145e5f28a1a is locked
  2015-06-18 19:09:23.852 16161 ERROR nova.cells.messaging

  Logstash query: message:"InstanceIsLocked" AND tags:"screen-n-cell-
  child.txt"

  http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiSW5zdGFuY2VJc0xvY2tlZFwiIEFORCB0YWdzOlwic2NyZWVuLW4tY2VsbC1jaGlsZC50eHRcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQzNDY3NDMyOTQ0Mn0=

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