yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1334345] [NEW] State expected powering off but is None

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Morgan Fainberg <morgan.fainberg@xxxxxxxxx>
Date: Wed, 25 Jun 2014 15:59:54 -0000
Reply-to: Bug 1334345 <1334345@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

It appears that nova compute is expecting (in a number of cases) an
instance to be in powering-off state, but the state is actually none.
This appears to have a wide range of failure modes.

I'm seeing this ~2800 times in the last 7 days

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

Example traceback:

UnexpectedTaskStateError: Unexpected task state: expecting (u'powering-off',) but the actual state is None
 to caller
2014-06-25 05:01:31.058 ERROR oslo.messaging._drivers.common [req-ae166761-731e-4ead-b9da-eb8e8b1cf6af None None] 
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
    incoming.message))
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
    return self._do_dispatch(endpoint, method, ctxt, args)
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
    result = getattr(endpoint, method)(ctxt, **new_args)
  File "/opt/stack/new/nova/nova/exception.py", line 88, in wrapped
    payload)
  File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/new/nova/nova/exception.py", line 71, in wrapped
    return f(self, context, *args, **kw)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 278, in decorated_function
    LOG.info(_("Task possibly preempted: %s") % e.format_message())
  File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 272, in decorated_function
    return function(self, context, *args, **kwargs)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 336, in decorated_function
    return function(self, context, *args, **kwargs)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 314, in decorated_function
    kwargs['instance'], e, sys.exc_info())
  File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 302, in decorated_function
    return function(self, context, *args, **kwargs)
  File "/opt/stack/new/nova/nova/compute/manager.py", line 2346, in stop_instance
    instance.save(expected_task_state=task_states.POWERING_OFF)
  File "/opt/stack/new/nova/nova/objects/base.py", line 187, in wrapper
    ctxt, self, fn.__name__, args, kwargs)
  File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 354, in object_action
    objmethod=objmethod, args=args, kwargs=kwargs)
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 152, in call
    retry=self.retry)
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send
    timeout=timeout, retry=retry)
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 401, in send
    retry=retry)
  File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 392, in _send
    raise result
UnexpectedTaskStateError_Remote: Unexpected task state: expecting (u'powering-off',) but the actual state is None
Traceback (most recent call last):

  File "/opt/stack/new/nova/nova/conductor/manager.py", line 404, in _object_dispatch
    return getattr(target, method)(context, *args, **kwargs)

  File "/opt/stack/new/nova/nova/objects/base.py", line 196, in wrapper
    return fn(self, ctxt, *args, **kwargs)

  File "/opt/stack/new/nova/nova/objects/instance.py", line 473, in save
    columns_to_join=_expected_cols(expected_attrs))

  File "/opt/stack/new/nova/nova/db/api.py", line 780, in instance_update_and_get_original
    columns_to_join=columns_to_join)

  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 164, in wrapper
    return f(*args, **kwargs)

  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2229, in instance_update_and_get_original
    columns_to_join=columns_to_join)

  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2280, in _instance_update
    actual=actual_state, expected=expected)

UnexpectedTaskStateError: Unexpected task state: expecting (u'powering-
off',) but the actual state is None

** Affects: nova
     Importance: Undecided
         Status: New

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

Title:
  State expected powering off but is None

Status in OpenStack Compute (Nova):
  New

Bug description:
  It appears that nova compute is expecting (in a number of cases) an
  instance to be in powering-off state, but the state is actually none.
  This appears to have a wide range of failure modes.

  I'm seeing this ~2800 times in the last 7 days

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

  Example traceback:

  UnexpectedTaskStateError: Unexpected task state: expecting (u'powering-off',) but the actual state is None
   to caller
  2014-06-25 05:01:31.058 ERROR oslo.messaging._drivers.common [req-ae166761-731e-4ead-b9da-eb8e8b1cf6af None None] 
  Traceback (most recent call last):
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
      incoming.message))
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
      return self._do_dispatch(endpoint, method, ctxt, args)
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
      result = getattr(endpoint, method)(ctxt, **new_args)
    File "/opt/stack/new/nova/nova/exception.py", line 88, in wrapped
      payload)
    File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
      six.reraise(self.type_, self.value, self.tb)
    File "/opt/stack/new/nova/nova/exception.py", line 71, in wrapped
      return f(self, context, *args, **kw)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 278, in decorated_function
      LOG.info(_("Task possibly preempted: %s") % e.format_message())
    File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
      six.reraise(self.type_, self.value, self.tb)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 272, in decorated_function
      return function(self, context, *args, **kwargs)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 336, in decorated_function
      return function(self, context, *args, **kwargs)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 314, in decorated_function
      kwargs['instance'], e, sys.exc_info())
    File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
      six.reraise(self.type_, self.value, self.tb)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 302, in decorated_function
      return function(self, context, *args, **kwargs)
    File "/opt/stack/new/nova/nova/compute/manager.py", line 2346, in stop_instance
      instance.save(expected_task_state=task_states.POWERING_OFF)
    File "/opt/stack/new/nova/nova/objects/base.py", line 187, in wrapper
      ctxt, self, fn.__name__, args, kwargs)
    File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 354, in object_action
      objmethod=objmethod, args=args, kwargs=kwargs)
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 152, in call
      retry=self.retry)
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send
      timeout=timeout, retry=retry)
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 401, in send
      retry=retry)
    File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 392, in _send
      raise result
  UnexpectedTaskStateError_Remote: Unexpected task state: expecting (u'powering-off',) but the actual state is None
  Traceback (most recent call last):

    File "/opt/stack/new/nova/nova/conductor/manager.py", line 404, in _object_dispatch
      return getattr(target, method)(context, *args, **kwargs)

    File "/opt/stack/new/nova/nova/objects/base.py", line 196, in wrapper
      return fn(self, ctxt, *args, **kwargs)

    File "/opt/stack/new/nova/nova/objects/instance.py", line 473, in save
      columns_to_join=_expected_cols(expected_attrs))

    File "/opt/stack/new/nova/nova/db/api.py", line 780, in instance_update_and_get_original
      columns_to_join=columns_to_join)

    File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 164, in wrapper
      return f(*args, **kwargs)

    File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2229, in instance_update_and_get_original
      columns_to_join=columns_to_join)

    File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2280, in _instance_update
      actual=actual_state, expected=expected)

  UnexpectedTaskStateError: Unexpected task state: expecting (u
  'powering-off',) but the actual state is None

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

[Bug 1334345] Re: Unexpected task state: expecting [None] but the actual state is powering-off
From: Russell Bryant, 2014-07-23
[Bug 1334345] [NEW] State expected powering off but is None
From: Morgan Fainberg, 2014-06-25
References

[Bug 1334345] [NEW] State expected powering off but is None
From: Morgan Fainberg, 2014-06-25