Public bug reported: Nova instance actions periodically have no start and finish time, I get empty events[]:
root@controller1:/var/log# nova instance-action-list 5f844d05-405f-4997-b542-0c85d1b6c8ed +--------+------------------------------------------+---------+----------------------------+ | Action | Request_ID | Message | Start_Time | +--------+------------------------------------------+---------+----------------------------+ | create | req-58d31051-ca3b-4a1c-ab75-0335ff3b28ae | - | 2016-01-21T11:24:07.000000 | | reboot | req-eba0435f-610a-47cd-841f-f3500c7b66b7 | - | 2016-01-21T11:25:47.000000 | | reboot | req-71688344-840e-4cb4-ba3e-21e4c0a85db7 | - | 2016-01-21T11:26:17.000000 | +--------+------------------------------------------+---------+----------------------------+ root@controller1:/var/log# nova instance-action 5f844d05-405f-4997-b542-0c85d1b6c8ed req-eba0435f-610a-47cd-841f-f3500c7b66b7 +---------------+--------------------------------------------------+ | Property | Value | +---------------+--------------------------------------------------+ | action | reboot | | events | [{u'event': u'compute_reboot_instance', | | | u'finish_time': u'2016-01-21T11:25:50.000000', | | | u'result': u'Success', | | | u'start_time': u'2016-01-21T11:25:48.000000', | | | u'traceback': None}] | | instance_uuid | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | message | - | | project_id | 73eb606e175249049987ec6a5774f282 | | request_id | req-eba0435f-610a-47cd-841f-f3500c7b66b7 | | start_time | 2016-01-21T11:25:47.000000 | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +---------------+--------------------------------------------------+ root@controller1:/var/log# nova instance-action 5f844d05-405f-4997-b542-0c85d1b6c8ed req-71688344-840e-4cb4-ba3e-21e4c0a85db7 +---------------+------------------------------------------+ | Property | Value | +---------------+------------------------------------------+ | action | reboot | | events | [] | | instance_uuid | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | message | - | | project_id | 73eb606e175249049987ec6a5774f282 | | request_id | req-71688344-840e-4cb4-ba3e-21e4c0a85db7 | | start_time | 2016-01-21T11:26:17.000000 | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +---------------+------------------------------------------+ root@controller1:/var/log# nova show 5f844d05-405f-4997-b542-0c85d1b6c8ed +--------------------------------------+------------------------------------------------------------------------------------------+ | Property | Value | +--------------------------------------+------------------------------------------------------------------------------------------+ | OS-DCF:diskConfig | MANUAL | | OS-EXT-AZ:availability_zone | nova | | OS-EXT-SRV-ATTR:host | compute3 | | OS-EXT-SRV-ATTR:hypervisor_hostname | compute3.serverel.net | | OS-EXT-SRV-ATTR:instance_name | instance-0000010e | | OS-EXT-STS:power_state | 1 | | OS-EXT-STS:task_state | - | | OS-EXT-STS:vm_state | active | | OS-SRV-USG:launched_at | 2016-01-21T11:24:14.000000 | | OS-SRV-USG:terminated_at | - | | accessIPv4 | | | accessIPv6 | | | config_drive | | | created | 2016-01-21T11:24:08Z | | flavor | CL-1_PR-69_vCPUs-1_RAM-512_Disk-5_RxTx_Factor-1.0 (f807d233-1aec-44d5-828f-785137b0b687) | | hostId | 4b5575c8d545b442b101a6c6f9fd1f5224974e465b7bfcc43d90730a | | id | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | image | cirros (ea3dfccd-3099-4584-8cb8-6017bc3faa2a) | | key_name | - | | metadata | {} | | name | test12 | | os-extended-volumes:volumes_attached | [] | | progress | 0 | | pubnet1-591 network | 199.182.165.231 | | security_groups | default | | status | ACTIVE | | tenant_id | 73eb606e175249049987ec6a5774f282 | | updated | 2016-01-21T11:26:17Z | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +--------------------------------------+------------------------------------------------------------------------------------------+ In nova-compute.log at compute node for request req-71688344-840e-4cb4 -ba3e-21e4c0a85db7 I get: 2016-01-21 11:26:17.046 36019 DEBUG oslo_concurrency.lockutils [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker.update_usage" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:253 2016-01-21 11:26:17.093 36019 DEBUG oslo_concurrency.lockutils [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Lock "compute_resources" released by "nova.compute.resource_tracker.update_usage" :: held 0.047s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:265 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Exception during message handling: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher executor_callback)) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher executor_callback) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 89, in wrapped 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher payload) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 72, in wrapped 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return f(self, context, *args, **kw) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 350, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher LOG.warning(msg, e, instance=instance) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 323, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return function(self, context, *args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 399, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher with compute_utils.EventReporter(context, event_name, instance_uuid): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/utils.py", line 537, in __enter__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher self.context, uuid, self.event_name, want_result=False) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 169, in wrapper 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args, kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/rpcapi.py", line 229, in object_class_action 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args, kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/rpcapi.py", line 237, in object_class_action_versions 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args=args, kwargs=kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher retry=self.retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher timeout=timeout, retry=retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher retry=retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher raise result 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher InstanceActionNotFound_Remote: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 447, in _object_dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return getattr(target, method)(*args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 171, in wrapper 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher result = fn(cls, context, *args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/objects/instance_action.py", line 173, in event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher db_event = db.action_event_start(context, values) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 1806, in action_event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return IMPL.action_event_start(context, values) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 5768, in action_event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher instance_uuid=values['instance_uuid']) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher InstanceActionNotFound: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher For request req-eba0435f-610a-47cd-841f-f3500c7b66b7 instance rebooted successfully. The same problems with "InstanceActionNotFound" in nova-compute.log periodically happens with other actions (stop/start instances), but actions always finish successfully root@controller1:/var/log# dpkg -l | grep nova ii nova-api 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - API frontend ii nova-cert 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - certificate management ii nova-common 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - common files ii nova-conductor 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - conductor service ii nova-consoleauth 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - Console Authenticator ii nova-novncproxy 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - NoVNC proxy ii nova-scheduler 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - virtual machine scheduler ii python-nova 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute Python libraries ii python-novaclient 2:2.30.1-1~cloud0 all client library for OpenStack Compute API root@compute3:/etc# dpkg -l | grep nova ii nova-common 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - common files ii nova-compute 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node base ii nova-compute-kvm 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node (KVM) ii nova-compute-libvirt 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node libvirt support ii python-nova 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute Python libraries ii python-novaclient 2:2.30.1-1~cloud0 all client library for OpenStack Compute API ** 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/1536610 Title: nova instance actions periodically have no start and finish time (empty events[]) Status in OpenStack Compute (nova): New Bug description: Nova instance actions periodically have no start and finish time, I get empty events[]: root@controller1:/var/log# nova instance-action-list 5f844d05-405f-4997-b542-0c85d1b6c8ed +--------+------------------------------------------+---------+----------------------------+ | Action | Request_ID | Message | Start_Time | +--------+------------------------------------------+---------+----------------------------+ | create | req-58d31051-ca3b-4a1c-ab75-0335ff3b28ae | - | 2016-01-21T11:24:07.000000 | | reboot | req-eba0435f-610a-47cd-841f-f3500c7b66b7 | - | 2016-01-21T11:25:47.000000 | | reboot | req-71688344-840e-4cb4-ba3e-21e4c0a85db7 | - | 2016-01-21T11:26:17.000000 | +--------+------------------------------------------+---------+----------------------------+ root@controller1:/var/log# nova instance-action 5f844d05-405f-4997-b542-0c85d1b6c8ed req-eba0435f-610a-47cd-841f-f3500c7b66b7 +---------------+--------------------------------------------------+ | Property | Value | +---------------+--------------------------------------------------+ | action | reboot | | events | [{u'event': u'compute_reboot_instance', | | | u'finish_time': u'2016-01-21T11:25:50.000000', | | | u'result': u'Success', | | | u'start_time': u'2016-01-21T11:25:48.000000', | | | u'traceback': None}] | | instance_uuid | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | message | - | | project_id | 73eb606e175249049987ec6a5774f282 | | request_id | req-eba0435f-610a-47cd-841f-f3500c7b66b7 | | start_time | 2016-01-21T11:25:47.000000 | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +---------------+--------------------------------------------------+ root@controller1:/var/log# nova instance-action 5f844d05-405f-4997-b542-0c85d1b6c8ed req-71688344-840e-4cb4-ba3e-21e4c0a85db7 +---------------+------------------------------------------+ | Property | Value | +---------------+------------------------------------------+ | action | reboot | | events | [] | | instance_uuid | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | message | - | | project_id | 73eb606e175249049987ec6a5774f282 | | request_id | req-71688344-840e-4cb4-ba3e-21e4c0a85db7 | | start_time | 2016-01-21T11:26:17.000000 | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +---------------+------------------------------------------+ root@controller1:/var/log# nova show 5f844d05-405f-4997-b542-0c85d1b6c8ed +--------------------------------------+------------------------------------------------------------------------------------------+ | Property | Value | +--------------------------------------+------------------------------------------------------------------------------------------+ | OS-DCF:diskConfig | MANUAL | | OS-EXT-AZ:availability_zone | nova | | OS-EXT-SRV-ATTR:host | compute3 | | OS-EXT-SRV-ATTR:hypervisor_hostname | compute3.serverel.net | | OS-EXT-SRV-ATTR:instance_name | instance-0000010e | | OS-EXT-STS:power_state | 1 | | OS-EXT-STS:task_state | - | | OS-EXT-STS:vm_state | active | | OS-SRV-USG:launched_at | 2016-01-21T11:24:14.000000 | | OS-SRV-USG:terminated_at | - | | accessIPv4 | | | accessIPv6 | | | config_drive | | | created | 2016-01-21T11:24:08Z | | flavor | CL-1_PR-69_vCPUs-1_RAM-512_Disk-5_RxTx_Factor-1.0 (f807d233-1aec-44d5-828f-785137b0b687) | | hostId | 4b5575c8d545b442b101a6c6f9fd1f5224974e465b7bfcc43d90730a | | id | 5f844d05-405f-4997-b542-0c85d1b6c8ed | | image | cirros (ea3dfccd-3099-4584-8cb8-6017bc3faa2a) | | key_name | - | | metadata | {} | | name | test12 | | os-extended-volumes:volumes_attached | [] | | progress | 0 | | pubnet1-591 network | 199.182.165.231 | | security_groups | default | | status | ACTIVE | | tenant_id | 73eb606e175249049987ec6a5774f282 | | updated | 2016-01-21T11:26:17Z | | user_id | 8855a4b15321469c8b44bbc1e0ea5320 | +--------------------------------------+------------------------------------------------------------------------------------------+ In nova-compute.log at compute node for request req-71688344-840e-4cb4 -ba3e-21e4c0a85db7 I get: 2016-01-21 11:26:17.046 36019 DEBUG oslo_concurrency.lockutils [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker.update_usage" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:253 2016-01-21 11:26:17.093 36019 DEBUG oslo_concurrency.lockutils [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Lock "compute_resources" released by "nova.compute.resource_tracker.update_usage" :: held 0.047s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:265 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher [req-71688344-840e-4cb4-ba3e-21e4c0a85db7 8855a4b15321469c8b44bbc1e0ea5320 73eb606e175249049987ec6a5774f282 - - -] Exception during message handling: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher executor_callback)) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher executor_callback) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 89, in wrapped 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher payload) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 72, in wrapped 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return f(self, context, *args, **kw) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 350, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher LOG.warning(msg, e, instance=instance) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 323, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return function(self, context, *args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 399, in decorated_function 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher with compute_utils.EventReporter(context, event_name, instance_uuid): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/utils.py", line 537, in __enter__ 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher self.context, uuid, self.event_name, want_result=False) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 169, in wrapper 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args, kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/rpcapi.py", line 229, in object_class_action 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args, kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/rpcapi.py", line 237, in object_class_action_versions 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher args=args, kwargs=kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher retry=self.retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher timeout=timeout, retry=retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher retry=retry) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher raise result 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher InstanceActionNotFound_Remote: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last): 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 447, in _object_dispatch 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return getattr(target, method)(*args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 171, in wrapper 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher result = fn(cls, context, *args, **kwargs) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/objects/instance_action.py", line 173, in event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher db_event = db.action_event_start(context, values) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 1806, in action_event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher return IMPL.action_event_start(context, values) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 5768, in action_event_start 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher instance_uuid=values['instance_uuid']) 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher InstanceActionNotFound: Action for request_id req-71688344-840e-4cb4-ba3e-21e4c0a85db7 on instance 5f844d05-405f-4997-b542-0c85d1b6c8ed not found 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher 2016-01-21 11:26:17.102 36019 ERROR oslo_messaging.rpc.dispatcher For request req-eba0435f-610a-47cd-841f-f3500c7b66b7 instance rebooted successfully. The same problems with "InstanceActionNotFound" in nova-compute.log periodically happens with other actions (stop/start instances), but actions always finish successfully root@controller1:/var/log# dpkg -l | grep nova ii nova-api 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - API frontend ii nova-cert 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - certificate management ii nova-common 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - common files ii nova-conductor 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - conductor service ii nova-consoleauth 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - Console Authenticator ii nova-novncproxy 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - NoVNC proxy ii nova-scheduler 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - virtual machine scheduler ii python-nova 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute Python libraries ii python-novaclient 2:2.30.1-1~cloud0 all client library for OpenStack Compute API root@compute3:/etc# dpkg -l | grep nova ii nova-common 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - common files ii nova-compute 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node base ii nova-compute-kvm 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node (KVM) ii nova-compute-libvirt 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute - compute node libvirt support ii python-nova 2:12.0.0-0ubuntu2~cloud0 all OpenStack Compute Python libraries ii python-novaclient 2:2.30.1-1~cloud0 all client library for OpenStack Compute API To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1536610/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp