yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1595083] [NEW] Instance with powering-off task-state stop failure when the nova-compute restarts

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Tina Kevin <song.ruixia@xxxxxxxxxx>
Date: Wed, 22 Jun 2016 08:37:34 -0000
Reply-to: Bug 1595083 <1595083@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Description
===========
There is an active instance and stop the instance. When the task_state of the
instance is powering-off, then I restart the nova-compute services, the _init_instance
function will stop the instance again. The expected result is stop instance success and
instance is SHUTOFF, but now stop raise error.
code:
    if instance.task_state == task_states.POWERING_OFF:
      try:
         LOG.debug("Instance in transitional state %s at start-up "
             "retrying stop request",
             instance.task_state, instance=instance)
        self.stop_instance(context, instance)
      except Exception:
        # we don't want that an exception blocks the init_host
        msg = _LE('Failed to stop instance')
        LOG.exception(msg, instance=instance)
    return

The powering-on task-state also has the same issue.

Steps to reproduce
==================
A chronological list of steps which will bring off the
issue :
* I boot an instance
   nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic
   net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
* then I stop the instance
   nova stop test_iso8
* then I restart the nova-compute service when instance in powering-off task-state

Expected result
===============
When nova-compute service restart，the instance test_iso8 should be stopped.

Actual result
=============
After the nova-compute service restart, the instance test_iso8 is active.
The nova-compute.log has error information.

Environment
===========
1. Exact version of OpenStack you are running.
   Mitaka
2. Which hypervisor did you use?
   Libvirt + KVM
3. Which networking type did you use?
    Neutron with OpenVSwitch

Logs & Configs
==============
[root@slot4 ~(keystone_admin)]# nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
[root@slot4 ~(keystone_admin)]# nova stop test_iso8
Request to stop server test_iso8 has been accepted.

restart nova-compute service

[root@slot4 ~(keystone_admin)]# nova list
+--------------------------------------+-----------+--------+------------+-------------+-----------------+
| ID                                   | Name      | Status | Task State | Power State | Networks        |
+--------------------------------------+-----------+--------+------------+-------------+-----------------+
| 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 | test_iso8 | ACTIVE | -          | Running     | net01=5.5.5.249 |
+--------------------------------------+-----------+--------+------------+-------------+-----------------+
[root@slot4 ~(keystone_admin)]# nova instance-action-list 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9
+-------------------+------------------------------------------+---------+----------------------------+
| Action            | Request_ID                               | Message | Start_Time                 |
+-------------------+------------------------------------------+---------+----------------------------+
| create            | req-25400b17-6c33-45e5-ae4e-87cba0d0de15 | -       | 2016-06-22T04:40:43.000000 |
| stop              | req-5a7d26eb-79d3-4e69-86a8-d40c02bc6a00 | -       | 2016-06-22T07:08:23.000000 |
+-------------------+------------------------------------------+---------+----------------------------+

nova-compute.log error information:
2016-06-22 15:08:29.942 28875 ERROR nova.compute.manager [req-b6bbfa68-334c-4c31-9f6d-4d5523cebc4d - - - - -] [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Failed to stop instance
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1304, in _init_instance
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.stop_instance(context, instance)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     payload)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return f(self, context, *args, **kw)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 377, in decorated_function
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     LOG.warning(msg, e, instance_uuid=instance_uuid)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 348, in decorated_function
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return function(self, context, *args, **kwargs)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 426, in decorated_function
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     with compute_utils.EventReporter(context, event_name, instance_uuid):
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 540, in __enter__
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.context, uuid, self.event_name, want_result=False)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 161, in wrapper
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     args, kwargs)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 335, in object_class_action
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     objver=objver, args=args, kwargs=kwargs)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=self.retry)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     timeout=timeout, retry=retry)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=retry)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     raise result
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound_Remote: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 426, in _object_dispatch
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return getattr(target, method)(*args, **kwargs)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 163, in wrapper
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     result = fn(cls, context, *args, **kwargs)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/instance_action.py", line 170, in event_start
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     db_event = db.action_event_start(context, values)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 1858, in action_event_start
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return IMPL.action_event_start(context, values)
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5748, in action_event_start
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     instance_uuid=values['instance_uuid'])
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found

** Affects: nova
     Importance: Undecided
     Assignee: Tina Kevin (song-ruixia)
         Status: New


** Tags: nova-compute powering-off restart service stop

** Description changed:

  Description
  ===========
  There is an active instance and stop the instance. When the task_state of the
- instance is powering-off, then I restart the nova-compute services, the _init_instance 
- function will stop the instance again. The expected result is stop instance success and 
+ instance is powering-off, then I restart the nova-compute services, the _init_instance
+ function will stop the instance again. The expected result is stop instance success and
  instance is SHUTOFF, but now stop raise error.
  code:
          if instance.task_state == task_states.POWERING_OFF:
              try:
                  LOG.debug("Instance in transitional state %s at start-up "
                            "retrying stop request",
                            instance.task_state, instance=instance)
                  self.stop_instance(context, instance)
              except Exception:
                  # we don't want that an exception blocks the init_host
                  msg = _LE('Failed to stop instance')
                  LOG.exception(msg, instance=instance)
              return
  
  The powering-on task-state also has the same issue.
  
  Steps to reproduce
  ==================
  A chronological list of steps which will bring off the
  issue :
- * I boot an instance 
-    nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic 
-    net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
+ * I boot an instance
+    nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic
+    net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  * then I stop the instance
-    nova stop test_iso8
+    nova stop test_iso8
  * then I restart the nova-compute service when instance in powering-off task-state
  
  Expected result
  ===============
  When nova-compute service restart，the instance test_iso8 should be stopped.
  
  Actual result
  =============
  After the nova-compute service restart, the instance test_iso8 is active.
  The nova-compute.log has error information.
  
  Environment
  ===========
- 1. Exact version of OpenStack you are running. 
-    Mitaka
+ 1. Exact version of OpenStack you are running.
+    Mitaka
  2. Which hypervisor did you use?
     Libvirt + KVM
  3. Which networking type did you use?
      Neutron with OpenVSwitch
  
  Logs & Configs
  ==============
  [root@slot4 ~(keystone_admin)]# nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  [root@slot4 ~(keystone_admin)]# nova stop test_iso8
  Request to stop server test_iso8 has been accepted.
  
  restart nova-compute service
  
  [root@slot4 ~(keystone_admin)]# nova list
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | ID                                   | Name      | Status | Task State | Power State | Networks        |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 | test_iso8 | ACTIVE | -          | Running     | net01=5.5.5.249 |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  [root@slot4 ~(keystone_admin)]# nova instance-action-list 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9
  +-------------------+------------------------------------------+---------+----------------------------+
  | Action            | Request_ID                               | Message | Start_Time                 |
  +-------------------+------------------------------------------+---------+----------------------------+
  | create            | req-25400b17-6c33-45e5-ae4e-87cba0d0de15 | -       | 2016-06-22T04:40:43.000000 |
  | stop              | req-5a7d26eb-79d3-4e69-86a8-d40c02bc6a00 | -       | 2016-06-22T07:08:23.000000 |
  +-------------------+------------------------------------------+---------+----------------------------+
  
  nova-compute.log error information:
  2016-06-22 15:08:29.942 28875 ERROR nova.compute.manager [req-b6bbfa68-334c-4c31-9f6d-4d5523cebc4d - - - - -] [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Failed to stop instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1304, in _init_instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.stop_instance(context, instance)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     payload)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return f(self, context, *args, **kw)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 377, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     LOG.warning(msg, e, instance_uuid=instance_uuid)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 348, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return function(self, context, *args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 426, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     with compute_utils.EventReporter(context, event_name, instance_uuid):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 540, in __enter__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.context, uuid, self.event_name, want_result=False)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 161, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     args, kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 335, in object_class_action
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     objver=objver, args=args, kwargs=kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=self.retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     timeout=timeout, retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     raise result
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound_Remote: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 426, in _object_dispatch
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return getattr(target, method)(*args, **kwargs)
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 163, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     result = fn(cls, context, *args, **kwargs)
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/instance_action.py", line 170, in event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     db_event = db.action_event_start(context, values)
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 1858, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return IMPL.action_event_start(context, values)
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5748, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     instance_uuid=values['instance_uuid'])
- 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] 
+ 2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found

** Description changed:

  Description
  ===========
  There is an active instance and stop the instance. When the task_state of the
  instance is powering-off, then I restart the nova-compute services, the _init_instance
  function will stop the instance again. The expected result is stop instance success and
  instance is SHUTOFF, but now stop raise error.
  code:
-         if instance.task_state == task_states.POWERING_OFF:
-             try:
-                 LOG.debug("Instance in transitional state %s at start-up "
-                           "retrying stop request",
-                           instance.task_state, instance=instance)
-                 self.stop_instance(context, instance)
-             except Exception:
-                 # we don't want that an exception blocks the init_host
-                 msg = _LE('Failed to stop instance')
-                 LOG.exception(msg, instance=instance)
-             return
+     if instance.task_state == task_states.POWERING_OFF:
+       try:
+          LOG.debug("Instance in transitional state %s at start-up "
+              "retrying stop request",
+              instance.task_state, instance=instance)
+         self.stop_instance(context, instance)
+       except Exception:
+         # we don't want that an exception blocks the init_host
+         msg = _LE('Failed to stop instance')
+         LOG.exception(msg, instance=instance)
+     return
  
  The powering-on task-state also has the same issue.
  
  Steps to reproduce
  ==================
  A chronological list of steps which will bring off the
  issue :
  * I boot an instance
     nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic
     net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  * then I stop the instance
     nova stop test_iso8
  * then I restart the nova-compute service when instance in powering-off task-state
  
  Expected result
  ===============
  When nova-compute service restart，the instance test_iso8 should be stopped.
  
  Actual result
  =============
  After the nova-compute service restart, the instance test_iso8 is active.
  The nova-compute.log has error information.
  
  Environment
  ===========
  1. Exact version of OpenStack you are running.
     Mitaka
  2. Which hypervisor did you use?
     Libvirt + KVM
  3. Which networking type did you use?
      Neutron with OpenVSwitch
  
  Logs & Configs
  ==============
  [root@slot4 ~(keystone_admin)]# nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  [root@slot4 ~(keystone_admin)]# nova stop test_iso8
  Request to stop server test_iso8 has been accepted.
  
  restart nova-compute service
  
  [root@slot4 ~(keystone_admin)]# nova list
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | ID                                   | Name      | Status | Task State | Power State | Networks        |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 | test_iso8 | ACTIVE | -          | Running     | net01=5.5.5.249 |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  [root@slot4 ~(keystone_admin)]# nova instance-action-list 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9
  +-------------------+------------------------------------------+---------+----------------------------+
  | Action            | Request_ID                               | Message | Start_Time                 |
  +-------------------+------------------------------------------+---------+----------------------------+
  | create            | req-25400b17-6c33-45e5-ae4e-87cba0d0de15 | -       | 2016-06-22T04:40:43.000000 |
  | stop              | req-5a7d26eb-79d3-4e69-86a8-d40c02bc6a00 | -       | 2016-06-22T07:08:23.000000 |
  +-------------------+------------------------------------------+---------+----------------------------+
  
  nova-compute.log error information:
  2016-06-22 15:08:29.942 28875 ERROR nova.compute.manager [req-b6bbfa68-334c-4c31-9f6d-4d5523cebc4d - - - - -] [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Failed to stop instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1304, in _init_instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.stop_instance(context, instance)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     payload)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return f(self, context, *args, **kw)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 377, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     LOG.warning(msg, e, instance_uuid=instance_uuid)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 348, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return function(self, context, *args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 426, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     with compute_utils.EventReporter(context, event_name, instance_uuid):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 540, in __enter__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.context, uuid, self.event_name, want_result=False)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 161, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     args, kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 335, in object_class_action
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     objver=objver, args=args, kwargs=kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=self.retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     timeout=timeout, retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     raise result
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound_Remote: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 426, in _object_dispatch
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return getattr(target, method)(*args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 163, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     result = fn(cls, context, *args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/instance_action.py", line 170, in event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     db_event = db.action_event_start(context, values)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 1858, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return IMPL.action_event_start(context, values)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5748, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     instance_uuid=values['instance_uuid'])
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found

** Changed in: nova
     Assignee: (unassigned) => Tina Kevin (song-ruixia)

** Tags added: nova-compute powering-off service stop

** Tags added: restart

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

Title:
  Instance with powering-off task-state stop failure when the nova-
  compute restarts

Status in OpenStack Compute (nova):
  New

Bug description:
  Description
  ===========
  There is an active instance and stop the instance. When the task_state of the
  instance is powering-off, then I restart the nova-compute services, the _init_instance
  function will stop the instance again. The expected result is stop instance success and
  instance is SHUTOFF, but now stop raise error.
  code:
      if instance.task_state == task_states.POWERING_OFF:
        try:
           LOG.debug("Instance in transitional state %s at start-up "
               "retrying stop request",
               instance.task_state, instance=instance)
          self.stop_instance(context, instance)
        except Exception:
          # we don't want that an exception blocks the init_host
          msg = _LE('Failed to stop instance')
          LOG.exception(msg, instance=instance)
      return

  The powering-on task-state also has the same issue.

  Steps to reproduce
  ==================
  A chronological list of steps which will bring off the
  issue :
  * I boot an instance
     nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic
     net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  * then I stop the instance
     nova stop test_iso8
  * then I restart the nova-compute service when instance in powering-off task-state

  Expected result
  ===============
  When nova-compute service restart，the instance test_iso8 should be stopped.

  Actual result
  =============
  After the nova-compute service restart, the instance test_iso8 is active.
  The nova-compute.log has error information.

  Environment
  ===========
  1. Exact version of OpenStack you are running.
     Mitaka
  2. Which hypervisor did you use?
     Libvirt + KVM
  3. Which networking type did you use?
      Neutron with OpenVSwitch

  Logs & Configs
  ==============
  [root@slot4 ~(keystone_admin)]# nova boot --flavor 2 --image c61966bd-7969-40af-9f9b-ed282fb25bdf --nic net-id=ea2a9eb5-f52e-4822-aa5d-168658e9c383  test_iso8
  [root@slot4 ~(keystone_admin)]# nova stop test_iso8
  Request to stop server test_iso8 has been accepted.

  restart nova-compute service

  [root@slot4 ~(keystone_admin)]# nova list
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | ID                                   | Name      | Status | Task State | Power State | Networks        |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  | 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 | test_iso8 | ACTIVE | -          | Running     | net01=5.5.5.249 |
  +--------------------------------------+-----------+--------+------------+-------------+-----------------+
  [root@slot4 ~(keystone_admin)]# nova instance-action-list 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9
  +-------------------+------------------------------------------+---------+----------------------------+
  | Action            | Request_ID                               | Message | Start_Time                 |
  +-------------------+------------------------------------------+---------+----------------------------+
  | create            | req-25400b17-6c33-45e5-ae4e-87cba0d0de15 | -       | 2016-06-22T04:40:43.000000 |
  | stop              | req-5a7d26eb-79d3-4e69-86a8-d40c02bc6a00 | -       | 2016-06-22T07:08:23.000000 |
  +-------------------+------------------------------------------+---------+----------------------------+

  nova-compute.log error information:
  2016-06-22 15:08:29.942 28875 ERROR nova.compute.manager [req-b6bbfa68-334c-4c31-9f6d-4d5523cebc4d - - - - -] [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Failed to stop instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1304, in _init_instance
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.stop_instance(context, instance)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     payload)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return f(self, context, *args, **kw)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 377, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     LOG.warning(msg, e, instance_uuid=instance_uuid)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     six.reraise(self.type_, self.value, self.tb)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 348, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return function(self, context, *args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 426, in decorated_function
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     with compute_utils.EventReporter(context, event_name, instance_uuid):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 540, in __enter__
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     self.context, uuid, self.event_name, want_result=False)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 161, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     args, kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 335, in object_class_action
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     objver=objver, args=args, kwargs=kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=self.retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     timeout=timeout, retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     retry=retry)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     raise result
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound_Remote: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] Traceback (most recent call last):
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 426, in _object_dispatch
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return getattr(target, method)(*args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 163, in wrapper
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     result = fn(cls, context, *args, **kwargs)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/objects/instance_action.py", line 170, in event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     db_event = db.action_event_start(context, values)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 1858, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     return IMPL.action_event_start(context, values)
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5748, in action_event_start
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]     instance_uuid=values['instance_uuid'])
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9]
  2016-06-22 15:08:29.942 28875 TRACE nova.compute.manager [instance: 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9] InstanceActionNotFound: Action for request_id req-e8ef400f-ca1b-4252-a2aa-9d749cd57ae4 on instance 40d78f1d-38fc-4bfb-8e7e-a3dfe60398d9 not found

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

[Bug 1595083] Re: Instance with powering-off task-state stop failure when the nova-compute restarts
From: Tina Kevin, 2016-06-24