Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1456845

Summary:	[OSP10] list.remove(x): x not in list when creating a thread
Product:	Red Hat OpenStack	Reporter:	Irina Petrova <ipetrova>
Component:	python-oslo-service	Assignee:	Victor Stinner <vstinner>
Status:	CLOSED ERRATA	QA Contact:	Udi Shkalim <ushkalim>
Severity:	high	Docs Contact:
Priority:	high
Version:	10.0 (Newton)	CC:	fdinitto, pablo.iranzo, pcaruana, therve, vstinner
Target Milestone:	z4	Keywords:	Triaged, ZStream
Target Release:	10.0 (Newton)
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	python-oslo-service-1.16.0-2.el7ost	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	1457110 (view as bug list)		Environment:
Last Closed:	2017-09-06 17:06:29 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	1457110

Description Irina Petrova 2017-05-30 13:22:41 UTC

Description of problem:

Deployment (incl. new deployment, scaling in, scaling out, modifications of templates or post-install scripts) fails sporadically due to what it seems to be a race condition:

https://bugs.launchpad.net/oslo.service/+bug/1662939

Version-Release number of selected component (if applicable):
python-oslo-service-1.16.0-1.el7ost

Logs:
~~~
[ipetrova@collab-shell heat]$ grep -A25 Traceback heat-engine.log  -B5
2017-05-18 15:33:52.423 4686 DEBUG heat.engine.service [req-da463754-1824-44ac-8e3a-d5af945c197d - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] signaling resource overcloud-AllNodesDeploySteps-fjewneil7iow-ComputeDeployment_Step3-yvv22q5a2u7k:63 _resource_signal /usr/lib/python2.7/site-packages/heat/engine/service.py:1807
2017-05-18 15:33:52.455 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-b0c31edc-5863-4255-b938-711ffc5d01a8 - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: 25a04a43bfee4a67b418d9f9a7c52c2c reply queue: reply_90e65569d6454ca68fadbbedc388422f time elapsed: 0.0813218159892s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:52.464 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 0b896de6a9eb401cb854f575732dead2 reply to reply_90e65569d6454ca68fadbbedc388422f __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:194
2017-05-18 15:33:52.677 4685 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 25a04a43bfee4a67b418d9f9a7c52c2c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource [req-700d4d5a-75b0-4e40-a338-4aab8e8de514 - - - - -] Error marking resource as failed
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 783, in _action_recorder
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self.state_set(action, self.FAILED, msg)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1998, in state_set
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self._add_event(action, status, reason)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1756, in _add_event
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self.stack.dispatch_event(ev)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/stack.py", line 886, in dispatch_event
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     ev.as_dict())
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/service.py", line 143, in start
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     func, *args, **kwargs)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 96, in add_thread
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     th = Thread(gt, self)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 46, in __init__
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self.thread.link(_on_thread_done, group, self)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 197, in link
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self._resolve_links()
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 232, in _resolve_links
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     f(self, *ca, **ckw)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 34, in _on_thread_done
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     group.thread_done(thread)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 101, in thread_done
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource     self.threads.remove(thread)
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource ValueError: list.remove(x): x not in list
2017-05-18 15:33:52.471 4686 ERROR heat.engine.resource 
2017-05-18 15:33:52.917 4686 DEBUG heat.engine.clients.keystoneclient [req-70ad538e-abe6-4e4b-b0ae-c575c68e113f - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] Using stack domain heat_stack __init__ /usr/lib/python2.7/site-packages/heat/engine/clients/os/keystone/heat_keystoneclient.py:98
--
2017-05-18 15:33:53.580 4685 DEBUG heat.engine.scheduler [req-6eaf0ad9-4d63-44d1-bce9-933621f3656b - - - - -] Task update_task from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] sleeping _sleep /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:157
2017-05-18 15:33:53.611 4686 DEBUG heat.engine.clients.keystoneclient [req-c5e2ecb7-7d5c-4bdd-ae25-a824e184a7b9 - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] Using stack domain heat_stack __init__ /usr/lib/python2.7/site-packages/heat/engine/clients/os/keystone/heat_keystoneclient.py:98
2017-05-18 15:33:53.162 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-c5e2ecb7-7d5c-4bdd-ae25-a824e184a7b9 - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: 20106fbb0f2248cfa0af150af6985e96 reply queue: reply_5d9f8f85287b4a7686135e10bffdb8bf time elapsed: 255.413293763s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:53.162 4686 DEBUG heat.engine.service [req-c5e2ecb7-7d5c-4bdd-ae25-a824e184a7b9 - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] signaling resource overcloud-AllNodesDeploySteps-fjewneil7iow-ComputeDeployment_Step3-yvv22q5a2u7k:16 _resource_signal /usr/lib/python2.7/site-packages/heat/engine/service.py:1807
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource [req-700d4d5a-75b0-4e40-a338-4aab8e8de514 - - - - -] Error marking resource as failed
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 783, in _action_recorder
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self.state_set(action, self.FAILED, msg)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1998, in state_set
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self._add_event(action, status, reason)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1756, in _add_event
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self.stack.dispatch_event(ev)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/stack.py", line 886, in dispatch_event
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     ev.as_dict())
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/service.py", line 143, in start
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     func, *args, **kwargs)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 96, in add_thread
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     th = Thread(gt, self)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 46, in __init__
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self.thread.link(_on_thread_done, group, self)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 197, in link
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self._resolve_links()
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 232, in _resolve_links
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     f(self, *ca, **ckw)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 34, in _on_thread_done
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     group.thread_done(thread)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/oslo_service/threadgroup.py", line 101, in thread_done
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource     self.threads.remove(thread)
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource ValueError: list.remove(x): x not in list
2017-05-18 15:33:53.168 4686 ERROR heat.engine.resource 
2017-05-18 15:33:53.385 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-bd4ef947-15cf-4266-8949-95924d59fdab - 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] CALL msg_id: 28f5eb36788949d8a50dfa2918bb8182 exchange 'heat' topic 'engine' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:448
--
2017-05-18 15:33:54.580 4685 DEBUG heat.engine.scheduler [req-6eaf0ad9-4d63-44d1-bce9-933621f3656b - - - - -] Task Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:54.581 4685 DEBUG heat.engine.scheduler [req-6eaf0ad9-4d63-44d1-bce9-933621f3656b - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:54.581 4685 DEBUG heat.engine.scheduler [req-6eaf0ad9-4d63-44d1-bce9-933621f3656b - - - - -] Task _run_to_completion from StructuredDeploymentGroup "ComputeDeployment_Step3" [0ad79fc1-fb55-4827-8354-d553c3fc49a8] Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:54.584 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] CALL msg_id: 0926892640224953b7693e333147d844 exchange 'heat' topic 'engine' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:448
2017-05-18 15:33:54.584 4685 INFO heat.engine.resource [req-6eaf0ad9-4d63-44d1-bce9-933621f3656b - - - - -] UPDATE: StructuredDeploymentGroup "ComputeDeployment_Step3" [0ad79fc1-fb55-4827-8354-d553c3fc49a8] Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28]
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 763, in _action_recorder
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     yield
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1338, in update
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     prop_diff])
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 353, in wrapper
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     step = next(subtask)
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 816, in action_handler_task
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     done = check(handler_data)
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/openstack/heat/resource_group.py", line 396, in check_update_complete
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     if not checker.step():
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 219, in step
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     poll_period = next(self._runner)
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/openstack/heat/resource_group.py", line 384, in _run_to_completion
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     self).check_update_complete(updater):
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 505, in check_update_complete
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     cookie=cookie)
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 405, in _check_status_complete
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource     action=action)
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource ResourceFailure: resources.ComputeDeployment_Step3: list.remove(x): x not in list
2017-05-18 15:33:54.584 4685 ERROR heat.engine.resource 
2017-05-18 15:33:54.587 4685 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 0926892640224953b7693e333147d844 reply to reply_d3c7089c1303440e8728b221a6f7e79c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:194
2017-05-18 15:33:54.620 4685 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: 0926892640224953b7693e333147d844 reply queue: reply_d3c7089c1303440e8728b221a6f7e79c time elapsed: 0.0310467380041s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:54.622 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 0926892640224953b7693e333147d844 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
2017-05-18 15:33:54.625 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: 3f4d689a01904260adffe4b343601a6d reply queue: reply_d3c7089c1303440e8728b221a6f7e79c time elapsed: 0.0780052440241s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:54.627 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3f4d689a01904260adffe4b343601a6d __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
--
2017-05-18 15:33:55.571 4685 DEBUG heat.engine.scheduler [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] Task update_task from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:55.572 4685 DEBUG heat.engine.scheduler [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] Task Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:55.572 4685 DEBUG heat.engine.scheduler [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:33:55.578 4685 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: af357e871fc444b3be566e2663a762c4 reply queue: reply_d3c7089c1303440e8728b221a6f7e79c time elapsed: 0.0310862770129s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:55.579 4685 INFO heat.engine.resource [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] UPDATE: TemplateResource "AllNodesDeploySteps" [8a4070de-8f82-4608-a89c-19383c333e28] Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc]
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 763, in _action_recorder
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     yield
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1338, in update
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     prop_diff])
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 353, in wrapper
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     step = next(subtask)
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 816, in action_handler_task
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     done = check(handler_data)
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 505, in check_update_complete
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     cookie=cookie)
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 405, in _check_status_complete
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource     action=action)
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource ResourceFailure: resources.AllNodesDeploySteps: resources.ComputeDeployment_Step3: list.remove(x): x not in list
2017-05-18 15:33:55.579 4685 ERROR heat.engine.resource 
2017-05-18 15:33:55.580 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: af357e871fc444b3be566e2663a762c4 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
2017-05-18 15:33:55.582 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: b07078b2e6df4738a80b926b217f023c reply queue: reply_d3c7089c1303440e8728b221a6f7e79c time elapsed: 0.0750545999908s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:55.584 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: b07078b2e6df4738a80b926b217f023c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
2017-05-18 15:33:55.585 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-731fe3bb-5661-475c-92b2-759fd6d28429 - - - - -] CALL msg_id: 3967ce324f07403ab44d6924b75b7a60 exchange 'heat' topic 'engine' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:448
2017-05-18 15:33:55.588 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 3967ce324f07403ab44d6924b75b7a60 reply to reply_d3c7089c1303440e8728b221a6f7e79c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:194
2017-05-18 15:33:55.614 4685 DEBUG heat.engine.event [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] event's resource_properties too large to store at 98863 bytes store /usr/lib/python2.7/site-packages/heat/engine/event.py:81
2017-05-18 15:33:55.615 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-e42d9063-8e42-47d5-bc3b-112e3d0fee5e 8407d81416594b3d92d035c2fe9e168c 761f5226e1014b8f8cb5a7dae3c3bf6d - - -] sending reply msg_id: 3967ce324f07403ab44d6924b75b7a60 reply queue: reply_d3c7089c1303440e8728b221a6f7e79c time elapsed: 0.0260727780114s _send_reply /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:73
2017-05-18 15:33:55.617 4686 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 3967ce324f07403ab44d6924b75b7a60 __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:296
2017-05-18 15:33:55.619 4686 DEBUG oslo_messaging._drivers.amqpdriver [req-731fe3bb-5661-475c-92b2-759fd6d28429 - - - - -] CALL msg_id: 1072c9ab1fac4bfc993cff5c1d159af7 exchange 'heat' topic 'engine' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:448
2017-05-18 15:33:55.621 4685 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 1072c9ab1fac4bfc993cff5c1d159af7 reply to reply_d3c7089c1303440e8728b221a6f7e79c __call__ /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:194
2017-05-18 15:33:55.650 4685 DEBUG heat.engine.scheduler [req-c04bde18-0044-415b-9d2d-6c606532cd7c - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
--
2017-05-18 15:59:38.085 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task update_task from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:38.085 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:38.085 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:38.086 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _run_to_completion from StructuredDeploymentGroup "ComputeDeployment_Step2" [0ec3dfc3-27cf-45cf-90a1-ee971b0828a0] Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:38.089 4685 INFO heat.engine.resource [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] UPDATE: StructuredDeploymentGroup "ComputeDeployment_Step2" [0ec3dfc3-27cf-45cf-90a1-ee971b0828a0] Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28]
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 763, in _action_recorder
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     yield
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1338, in update
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     prop_diff])
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 353, in wrapper
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     step = next(subtask)
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 816, in action_handler_task
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     done = check(handler_data)
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/openstack/heat/resource_group.py", line 396, in check_update_complete
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     if not checker.step():
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 219, in step
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     poll_period = next(self._runner)
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/openstack/heat/resource_group.py", line 384, in _run_to_completion
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     self).check_update_complete(updater):
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 505, in check_update_complete
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     cookie=cookie)
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 405, in _check_status_complete
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource     action=action)
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource ResourceFailure: resources.ComputeDeployment_Step2: list.remove(x): x not in list
2017-05-18 15:59:38.089 4685 ERROR heat.engine.resource 
2017-05-18 15:59:38.116 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:38.116 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:38.116 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:38.117 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:38.117 4685 DEBUG heat.engine.scheduler [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Task _resource_update from Stack "overcloud-AllNodesDeploySteps-fjewneil7iow" [8a4070de-8f82-4608-a89c-19383c333e28] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
--
2017-05-18 15:59:38.265 4685 DEBUG heat.engine.stack_lock [req-6bebc6be-25b3-46b8-a8e4-5d09a1d30460 - - - - -] Engine d4e91f38-44d5-4f70-b0ea-757b7a82c881 released lock on stack 8a4070de-8f82-4608-a89c-19383c333e28 release /usr/lib/python2.7/site-packages/heat/engine/stack_lock.py:124
2017-05-18 15:59:39.082 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task update_task from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:39.082 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:39.083 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:216
2017-05-18 15:59:39.087 4685 INFO heat.engine.resource [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] UPDATE: TemplateResource "AllNodesDeploySteps" [8a4070de-8f82-4608-a89c-19383c333e28] Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc]
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource Traceback (most recent call last):
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 763, in _action_recorder
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     yield
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 1338, in update
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     prop_diff])
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 353, in wrapper
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     step = next(subtask)
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 816, in action_handler_task
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     done = check(handler_data)
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 505, in check_update_complete
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     cookie=cookie)
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", line 405, in _check_status_complete
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource     action=action)
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource ResourceFailure: resources.AllNodesDeploySteps: resources.ComputeDeployment_Step2: list.remove(x): x not in list
2017-05-18 15:59:39.087 4685 ERROR heat.engine.resource 
2017-05-18 15:59:39.120 4685 DEBUG heat.engine.event [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] event's resource_properties too large to store at 98863 bytes store /usr/lib/python2.7/site-packages/heat/engine/event.py:81
2017-05-18 15:59:39.131 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.131 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.131 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.131 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.131 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.132 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.132 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.132 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.132 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
2017-05-18 15:59:39.132 4685 DEBUG heat.engine.scheduler [req-e1237dc8-3868-44b7-b279-72e5f3ec44dd - - - - -] Task _resource_update from Stack "overcloud" [014eab00-48f6-44b7-bfae-1b1ff81adebc] Update cancelled cancel /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:280
~~~

Comment 3 Victor Stinner 2017-06-06 08:56:12 UTC

The package python-oslo-service-1.16.0-2.el7ost is now available for tests. It includes the fix for the https://review.openstack.org/469111 race condition.

Comment 17 Udi Shkalim 2017-08-17 14:12:44 UTC

Verified on python-oslo-service-1.16.1-1.el7ost.noarch

Multiple deployment on CI and manual deployments.

Comment 19 errata-xmlrpc 2017-09-06 17:06:29 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2653