** Changed in: nova
Status: Fix Committed => Fix Released
** Changed in: nova
Milestone: None => juno-3
--
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/1348661
Title:
nova.tests.api.ec2.test_cloud.CloudTestCase.test_terminate_instances_two_instances
race fails with UnexpectedDeletingTaskStateError
Status in OpenStack Compute (Nova):
Fix Released
Bug description:
This was being masked by bug 1311778 due to the MessagingTimeout
failure, but there are more specific errors.
http://logs.openstack.org/79/108879/1/gate/gate-nova-
python26/283e967/console.html#_2014-07-24_08_14_12_631
2014-07-24 08:14:12.631 | FAIL:
nova.tests.api.ec2.test_cloud.CloudTestCase.test_terminate_instances_two_instances
2014-07-24 08:14:12.631 | tags: worker-4
2014-07-24 08:14:12.631 |
----------------------------------------------------------------------
2014-07-24 08:14:12.631 | Empty attachments:
2014-07-24 08:14:12.631 | pythonlogging:'boto'
2014-07-24 08:14:12.631 | stderr
2014-07-24 08:14:12.631 | stdout
2014-07-24 08:14:12.631 |
2014-07-24 08:14:12.631 | pythonlogging:'': {{{
2014-07-24 08:14:12.631 | INFO [nova.network.driver] Loading network driver
'nova.network.linux_net'
2014-07-24 08:14:12.632 | AUDIT [nova.service] Starting conductor node
(version 2014.2)
2014-07-24 08:14:12.632 | INFO [nova.virt.driver] Loading compute driver
'nova.virt.fake.FakeDriver'
2014-07-24 08:14:12.632 | AUDIT [nova.service] Starting compute node (version
2014.2)
2014-07-24 08:14:12.632 | AUDIT [nova.compute.resource_tracker] Auditing
locally available compute resources
2014-07-24 08:14:12.632 | AUDIT [nova.compute.resource_tracker] Free ram
(MB): 7680
2014-07-24 08:14:12.632 | AUDIT [nova.compute.resource_tracker] Free disk
(GB): 1028
2014-07-24 08:14:12.632 | AUDIT [nova.compute.resource_tracker] Free VCPUS: 1
2014-07-24 08:14:12.632 | AUDIT [nova.compute.resource_tracker] PCI stats: []
2014-07-24 08:14:12.632 | INFO [nova.compute.resource_tracker]
Compute_service record created for 093d0c3802bf440db8f3f839963027c4:fake-mini
2014-07-24 08:14:12.632 | AUDIT [nova.service] Starting scheduler node
(version 2014.2)
2014-07-24 08:14:12.632 | INFO [nova.network.driver] Loading network driver
'nova.network.linux_net'
2014-07-24 08:14:12.633 | AUDIT [nova.service] Starting network node (version
2014.2)
2014-07-24 08:14:12.633 | AUDIT [nova.service] Starting consoleauth node
(version 2014.2)
2014-07-24 08:14:12.633 | AUDIT [nova.compute.manager] Starting instance...
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Attempting claim:
memory 2048 MB, disk 20 GB
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Total memory: 8192 MB,
used: 512.00 MB
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] memory limit not
specified, defaulting to unlimited
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Total disk: 1028 GB,
used: 0.00 GB
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] disk limit not
specified, defaulting to unlimited
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Claim successful
2014-07-24 08:14:12.633 | AUDIT [nova.compute.manager] Starting instance...
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Attempting claim:
memory 2048 MB, disk 20 GB
2014-07-24 08:14:12.633 | AUDIT [nova.compute.claims] Total memory: 8192 MB,
used: 2560.00 MB
2014-07-24 08:14:12.634 | AUDIT [nova.compute.claims] memory limit not
specified, defaulting to unlimited
2014-07-24 08:14:12.634 | AUDIT [nova.compute.claims] Total disk: 1028 GB,
used: 20.00 GB
2014-07-24 08:14:12.634 | AUDIT [nova.compute.claims] disk limit not
specified, defaulting to unlimited
2014-07-24 08:14:12.634 | AUDIT [nova.compute.claims] Claim successful
2014-07-24 08:14:12.634 | WARNING [nova.compute.manager] Instance is not
stopped. Calling the stop API.
2014-07-24 08:14:12.634 | ERROR [nova.compute.manager] error during stop() in
sync_power_state.
2014-07-24 08:14:12.634 | Traceback (most recent call last):
2014-07-24 08:14:12.634 | File "nova/compute/manager.py", line 5551, in
_sync_instance_power_state
2014-07-24 08:14:12.634 | self.compute_api.force_stop(context,
db_instance)
2014-07-24 08:14:12.634 | File "nova/compute/api.py", line 1767, in
force_stop
2014-07-24 08:14:12.634 | self.compute_rpcapi.stop_instance(context,
instance, do_cast=do_cast)
2014-07-24 08:14:12.635 | File "nova/compute/rpcapi.py", line 908, in
stop_instance
2014-07-24 08:14:12.635 | return rpc_method(ctxt, 'stop_instance',
instance=instance)
2014-07-24 08:14:12.635 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/client.py",
line 150, in call
2014-07-24 08:14:12.635 | wait_for_reply=True, timeout=timeout)
2014-07-24 08:14:12.635 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/transport.py",
line 90, in _send
2014-07-24 08:14:12.635 | timeout=timeout)
2014-07-24 08:14:12.635 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/_drivers/impl_fake.py",
line 166, in send
2014-07-24 08:14:12.635 | return self._send(target, ctxt, message,
wait_for_reply, timeout)
2014-07-24 08:14:12.635 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/_drivers/impl_fake.py",
line 161, in _send
2014-07-24 08:14:12.635 | 'No reply on topic %s' % target.topic)
2014-07-24 08:14:12.635 | MessagingTimeout: No reply on topic compute
2014-07-24 08:14:12.635 | AUDIT [nova.compute.manager] Terminating instance
2014-07-24 08:14:12.636 | INFO [nova.compute.manager] Task possibly
preempted: Unexpected task state: expecting ('powering-off',) but the actual
state is deleting
2014-07-24 08:14:12.636 | ERROR [oslo.messaging.rpc.dispatcher] Exception
during message handling: Unexpected task state: expecting ('powering-off',) but
the actual state is deleting
2014-07-24 08:14:12.636 | Traceback (most recent call last):
2014-07-24 08:14:12.636 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 133, in _dispatch_and_reply
2014-07-24 08:14:12.636 | incoming.message))
2014-07-24 08:14:12.636 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 176, in _dispatch
2014-07-24 08:14:12.636 | return self._do_dispatch(endpoint, method,
ctxt, args)
2014-07-24 08:14:12.636 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 122, in _do_dispatch
2014-07-24 08:14:12.636 | result = getattr(endpoint, method)(ctxt,
**new_args)
2014-07-24 08:14:12.636 | File "nova/exception.py", line 88, in wrapped
2014-07-24 08:14:12.636 | payload)
2014-07-24 08:14:12.636 | File "nova/openstack/common/excutils.py", line
82, in __exit__
2014-07-24 08:14:12.637 | six.reraise(self.type_, self.value, self.tb)
2014-07-24 08:14:12.637 | File "nova/exception.py", line 71, in wrapped
2014-07-24 08:14:12.637 | return f(self, context, *args, **kw)
2014-07-24 08:14:12.637 | File "nova/compute/manager.py", line 283, in
decorated_function
2014-07-24 08:14:12.637 | LOG.info(_("Task possibly preempted: %s") %
e.format_message())
2014-07-24 08:14:12.637 | File "nova/openstack/common/excutils.py", line
82, in __exit__
2014-07-24 08:14:12.637 | six.reraise(self.type_, self.value, self.tb)
2014-07-24 08:14:12.637 | File "nova/compute/manager.py", line 277, in
decorated_function
2014-07-24 08:14:12.637 | return function(self, context, *args, **kwargs)
2014-07-24 08:14:12.637 | File "nova/compute/manager.py", line 341, in
decorated_function
2014-07-24 08:14:12.637 | return function(self, context, *args, **kwargs)
2014-07-24 08:14:12.637 | File "nova/compute/manager.py", line 319, in
decorated_function
2014-07-24 08:14:12.638 | kwargs['instance'], e, sys.exc_info())
2014-07-24 08:14:12.638 | File "nova/openstack/common/excutils.py", line
82, in __exit__
2014-07-24 08:14:12.638 | six.reraise(self.type_, self.value, self.tb)
2014-07-24 08:14:12.638 | File "nova/compute/manager.py", line 307, in
decorated_function
2014-07-24 08:14:12.638 | return function(self, context, *args, **kwargs)
2014-07-24 08:14:12.638 | File "nova/compute/manager.py", line 2388, in
stop_instance
2014-07-24 08:14:12.638 | do_stop_instance()
2014-07-24 08:14:12.638 | File "nova/openstack/common/lockutils.py", line
325, in inner
2014-07-24 08:14:12.638 | return f(*args, **kwargs)
2014-07-24 08:14:12.638 | File "nova/compute/manager.py", line 2384, in
do_stop_instance
2014-07-24 08:14:12.638 |
instance.save(expected_task_state=task_states.POWERING_OFF)
2014-07-24 08:14:12.638 | File "nova/objects/base.py", line 196, in wrapper
2014-07-24 08:14:12.639 | return fn(self, ctxt, *args, **kwargs)
2014-07-24 08:14:12.639 | File "nova/objects/instance.py", line 469, in save
2014-07-24 08:14:12.639 | columns_to_join=_expected_cols(expected_attrs))
2014-07-24 08:14:12.639 | File "nova/db/api.py", line 780, in
instance_update_and_get_original
2014-07-24 08:14:12.639 | columns_to_join=columns_to_join)
2014-07-24 08:14:12.639 | File "nova/db/sqlalchemy/api.py", line 167, in
wrapper
2014-07-24 08:14:12.639 | return f(*args, **kwargs)
2014-07-24 08:14:12.639 | File "nova/db/sqlalchemy/api.py", line 2238, in
instance_update_and_get_original
2014-07-24 08:14:12.640 | columns_to_join=columns_to_join)
2014-07-24 08:14:12.640 | File "nova/db/sqlalchemy/api.py", line 2286, in
_instance_update
2014-07-24 08:14:12.640 | actual=actual_state, expected=expected)
2014-07-24 08:14:12.640 | UnexpectedDeletingTaskStateError: Unexpected task
state: expecting ('powering-off',) but the actual state is deleting
And this:
2014-07-24 08:14:12.643 | ERROR [oslo.messaging.rpc.dispatcher] Exception
during message handling: Object action obj_load_attr failed because: attribute
id not lazy-loadable
2014-07-24 08:14:12.643 | Traceback (most recent call last):
2014-07-24 08:14:12.643 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 133, in _dispatch_and_reply
2014-07-24 08:14:12.643 | incoming.message))
2014-07-24 08:14:12.643 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 176, in _dispatch
2014-07-24 08:14:12.643 | return self._do_dispatch(endpoint, method,
ctxt, args)
2014-07-24 08:14:12.643 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/rpc/dispatcher.py",
line 122, in _do_dispatch
2014-07-24 08:14:12.643 | result = getattr(endpoint, method)(ctxt,
**new_args)
2014-07-24 08:14:12.644 | File "nova/exception.py", line 88, in wrapped
2014-07-24 08:14:12.644 | payload)
2014-07-24 08:14:12.644 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/notify/notifier.py",
line 232, in error
2014-07-24 08:14:12.644 | self._notify(ctxt, event_type, payload, 'ERROR')
2014-07-24 08:14:12.644 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/notify/notifier.py",
line 278, in _notify
2014-07-24 08:14:12.644 | super(_SubNotifier, self)._notify(ctxt,
event_type, payload, priority)
2014-07-24 08:14:12.644 | File
"/home/jenkins/workspace/gate-nova-python26/.tox/py26/lib/python2.6/site-packages/oslo/messaging/notify/notifier.py",
line 151, in _notify
2014-07-24 08:14:12.644 | payload =
self._serializer.serialize_entity(ctxt, payload)
2014-07-24 08:14:12.644 | File "nova/rpc.py", line 106, in serialize_entity
2014-07-24 08:14:12.644 | return self._base.serialize_entity(context,
entity)
2014-07-24 08:14:12.644 | File "nova/rpc.py", line 95, in serialize_entity
2014-07-24 08:14:12.645 | return jsonutils.to_primitive(entity,
convert_instances=True)
2014-07-24 08:14:12.645 | File "nova/openstack/common/jsonutils.py", line
133, in to_primitive
2014-07-24 08:14:12.645 | return dict((k, recursive(v)) for k, v in
six.iteritems(value))
2014-07-24 08:14:12.645 | File "nova/openstack/common/jsonutils.py", line
133, in <genexpr>
2014-07-24 08:14:12.645 | return dict((k, recursive(v)) for k, v in
six.iteritems(value))
2014-07-24 08:14:12.645 | File "nova/openstack/common/jsonutils.py", line
133, in to_primitive
2014-07-24 08:14:12.645 | return dict((k, recursive(v)) for k, v in
six.iteritems(value))
2014-07-24 08:14:12.645 | File "nova/openstack/common/jsonutils.py", line
133, in <genexpr>
2014-07-24 08:14:12.645 | return dict((k, recursive(v)) for k, v in
six.iteritems(value))
2014-07-24 08:14:12.645 | File "nova/openstack/common/jsonutils.py", line
148, in to_primitive
2014-07-24 08:14:12.645 | return recursive(dict(value.iteritems()),
level=level + 1)
2014-07-24 08:14:12.646 | File "nova/objects/base.py", line 438, in
iteritems
2014-07-24 08:14:12.646 | yield name, getattr(self, name)
2014-07-24 08:14:12.646 | File "nova/objects/instance.py", line 229, in name
2014-07-24 08:14:12.646 | base_name = CONF.instance_name_template %
self.id
2014-07-24 08:14:12.646 | File "nova/objects/base.py", line 67, in getter
2014-07-24 08:14:12.646 | self.obj_load_attr(name)
2014-07-24 08:14:12.646 | File "nova/objects/instance.py", line 507, in
obj_load_attr
2014-07-24 08:14:12.646 | reason='attribute %s not lazy-loadable' %
attrname)
2014-07-24 08:14:12.646 | ObjectActionError: Object action obj_load_attr
failed because: attribute id not lazy-loadable
2014-07-24 08:14:12.646 | }}}
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1348661/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : [email protected]
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
