** Changed in: nova
Status: New => Opinion
** Changed in: nova
Importance: Undecided => Wishlist
--
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):
Opinion
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
