Deadlock error happened when adding action dependency during cluster creation. This error happened occasionally.
2016-05-10 22:25:59.769 31832 ERROR senlin.engine.actions.base [req-73722bc4-d2d4-4a98-90c8-e2172cb9bdf5 28198ebf0e56421da7a54a9147d9c080 9afdd59e748542eebdb2160e7062bdb7 - - - None] Unexpected exception occurred during action CLUSTER_CREATE (7c58c8e9-8f1d-49d9-bd96-025a4fdb4665) execution: (_mysql_exceptions.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO dependency (id, depended, dependent) VALUES (%s, %s, %s)'] [parameters: ('768813b8-4040-485f-9862-f024afcd963e', '1eb51bc9-bfac-4eb6-b398-5d1765b3ca14', '7c58c8e9-8f1d-49d9-bd96-025a4fdb4665')]
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base Traceback (most recent call last):
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/engine/actions/base.py", line 518, in ActionProc
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base result, reason = action.execute()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/engine/actions/cluster_action.py", line 845, in execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base res, reason = self._execute(**kwargs)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/engine/actions/cluster_action.py", line 813, in _execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base result, reason = method()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/engine/actions/cluster_action.py", line 186, in do_create
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base result, reason = self._create_nodes(self.cluster.desired_capacity)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/engine/actions/cluster_action.py", line 151, in _create_nodes
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base db_api.dependency_add(self.context, [a for a in child], self.id)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/db/api.py", line 336, in dependency_add
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base return IMPL.dependency_add(context, depended, dependent)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/openstack_repo/openstack/senlin/senlin/db/sqlalchemy/api.py", line 906, in dependency_add
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base synchronize_session=False)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3176, in update
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base update_op.exec_()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 1125, in exec_
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base self._do_pre()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "<string>", line 1, in <lambda>
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 1163, in _do_pre
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base session._autoflush()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1305, in _autoflush
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base self.flush()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2027, in flush
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base self._flush(objects)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2145, in _flush
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base transaction.rollback(_capture_exception=True)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base compat.reraise(exc_type, exc_value, exc_tb)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2109, in _flush
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base flush_context.execute()
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base rec.execute(self)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base uow
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base mapper, table, insert)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 800, in _emit_insert_statements
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base execute(statement, params)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base return meth(self, multiparams, params)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base return connection._execute_clauseelement(self, multiparams, params)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base compiled_sql, distilled_params
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base context)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base util.raise_from_cause(newraise, exc_info)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base reraise(type(exception), exception, tb=exc_tb)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base context)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base cursor.execute(statement, parameters)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base self.errorhandler(self, exc, value)
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base File "/home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base raise errorclass, errorvalue
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base DBDeadlock: (_mysql_exceptions.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO dependency (id, depended, dependent) VALUES (%s, %s, %s)'] [parameters: ('768813b8-4040-485f-9862-f024afcd963e', '1eb51bc9-bfac-4eb6-b398-5d1765b3ca14', '7c58c8e9-8f1d-49d9-bd96-025a4fdb4665')]
2016-05-10 22:25:59.769 31832 TRACE senlin.engine.actions.base
2016-05-10 22:26:00.118 31832 DEBUG oslo_messaging._drivers.amqpdriver [-] received message msg_id: 786376c3e9174e948eb57f04f842af6d reply to reply_e3fccdd46f5d41ab88fd47aed2c10575 __call__ /home/stack/huyanyan/python/virtualenv/SENLINENV/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:201
2016-05-10 22:26:00.123 31831 INFO senlin.engine.event [req-828a2578-e219-422d-a5bf-12bb119ac06d 172fee46b32647f797b9dcb4e352f31a c85f512b8a8e46baa7cc8ad6b86f49d7 - - - None] tempest-created-node-761359952 [74df0834] NODE_CHECK - SUCCEEDED: Node status is ACTIVE.
2016-05-10 22:26:00.323 31832 ERROR senlin.engine.event [req-73722bc4-d2d4-4a98-90c8-e2172cb9bdf5 28198ebf0e56421da7a54a9147d9c080 9afdd59e748542eebdb2160e7062bdb7 - - - None] tempest-created-cluster-1702857632 [7b53a755] CLUSTER_CREATE - FAILED: (_mysql_exceptions.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO dependency (id, depended, dependent) VALUES (%s, %s, %s)'] [parameters: ('768813b8-4040-485f-9862-f024afcd963e', '1eb51bc9-bfac-4eb6-b398-5d1765b3ca14', '7c58c8e9-8f1d-49d9-bd96-025a4fdb4665')]
Fix proposed to branch: master /review. openstack. org/318115
Review: https:/