Public bug reported:
While booting an instance, if save expected task_state is
"block_device_mapping", but it conflicts with actual task_state "spawning".
Then nova will raise RescheduledException and reschedule to another host.
original node nova-compute log:
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Traceback (most recent call
last):
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 86, in
_object_dispatch
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] return getattr(target,
method)(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 223, in
wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] return fn(self, *args,
**kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 701, in save
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
columns_to_join=_expected_cols(expected_attrs))
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/api.py", line 809, in
instance_update_and_get_original
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] expected=expected)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 229, in
wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] return f(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_db/api.py", line 148, in wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] ectxt.value = e.inner_exc
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] self.force_reraise()
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in
force_reraise
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] six.reraise(self.type_,
self.value, self.tb)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] return f(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 300, in
wrapped
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] return f(context, *args,
**kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2723, in
instance_update_and_get_original
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] context, instance_uuid,
values, expected, original=instance_ref))
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2859, in
_instance_update
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] raise exc(**exc_props)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] UnexpectedTaskStateError:
Conflict updating instance 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac. Expected:
{'task_state': [u'block_device_mapping']}. Actual: {'task_state': u'spawning'}
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR nova.compute.manager
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:53.500 2427 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Terminating instance
localhost nova-compute:2019-01-24 16:38:53.500 2427 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Terminating instance
reschedule node nova-compute log:
localhost nova-compute:2019-01-24 16:39:19.466 28548 INFO
nova.virt.libvirt.driver [-] [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
Instance spawned successfully.
localhost nova-compute:2019-01-24 16:39:19.466 28548 INFO
nova.virt.libvirt.driver [-] [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
Instance spawned successfully.
localhost nova-compute:2019-01-24 16:39:19.467 28548 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Took 6.32 seconds to spawn the instance
on the hypervisor.
localhost nova-compute:2019-01-24 16:39:19.467 28548 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Took 6.32 seconds to spawn the instance
on the hypervisor.
** Affects: nova
Importance: Undecided
Assignee: Dongcan Ye (hellochosen)
Status: New
** Changed in: nova
Assignee: (unassigned) => Dongcan Ye (hellochosen)
--
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/1813255
Title:
nova reschedule instance while updating instance task state
Status in OpenStack Compute (nova):
New
Bug description:
While booting an instance, if save expected task_state is
"block_device_mapping", but it conflicts with actual task_state "spawning".
Then nova will raise RescheduledException and reschedule to another host.
original node nova-compute log:
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Traceback
(most recent call last):
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 86, in
_object_dispatch
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
return getattr(target, method)(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 223, in
wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
return fn(self, *args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 701, in save
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
columns_to_join=_expected_cols(expected_attrs))
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/api.py", line 809, in
instance_update_and_get_original
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
expected=expected)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 229, in
wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
return f(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_db/api.py", line 148, in wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
ectxt.value = e.inner_exc
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
self.force_reraise()
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in
force_reraise
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
six.reraise(self.type_, self.value, self.tb)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
return f(*args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 300, in
wrapped
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
return f(context, *args, **kwargs)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2723, in
instance_update_and_get_original
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
context, instance_uuid, values, expected, original=instance_ref))
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] File
"/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2859, in
_instance_update
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] raise
exc(**exc_props)
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
UnexpectedTaskStateError: Conflict updating instance
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac. Expected: {'task_state':
[u'block_device_mapping']}. Actual: {'task_state': u'spawning'}
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:52.882 2427 ERROR
nova.compute.manager [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
localhost nova-compute:2019-01-24 16:38:53.500 2427 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Terminating instance
localhost nova-compute:2019-01-24 16:38:53.500 2427 INFO nova.compute.manager
[req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619 28be004cfb19402597149e00a9b4d813
ab9ba89406a64c76b8240da11f4b52d3 - - -] [instance:
0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Terminating instance
reschedule node nova-compute log:
localhost nova-compute:2019-01-24 16:39:19.466 28548 INFO
nova.virt.libvirt.driver [-] [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
Instance spawned successfully.
localhost nova-compute:2019-01-24 16:39:19.466 28548 INFO
nova.virt.libvirt.driver [-] [instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac]
Instance spawned successfully.
localhost nova-compute:2019-01-24 16:39:19.467 28548 INFO
nova.compute.manager [req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619
28be004cfb19402597149e00a9b4d813 ab9ba89406a64c76b8240da11f4b52d3 - - -]
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Took 6.32 seconds to spawn the
instance on the hypervisor.
localhost nova-compute:2019-01-24 16:39:19.467 28548 INFO
nova.compute.manager [req-2b6ee2e1-6f8e-4bc0-80d7-62e41ce02619
28be004cfb19402597149e00a9b4d813 ab9ba89406a64c76b8240da11f4b52d3 - - -]
[instance: 0b6fddfa-27e1-4e71-83dd-c5cd9035dbac] Took 6.32 seconds to spawn the
instance on the hypervisor.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1813255/+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
