Overcloud deploy failed with mistral engine error: "The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo [...]"

Issue

• Overcloud deploy failed with an error similar to this one:

$ openstack stack failures list overcloud --long 
overcloud.Compute.2.PreNetworkConfig:
  resource_type: OS::TripleO::Compute::PreNetworkConfig
  physical_resource_id: 58c05d2c-502b-48e9-8a22-4fd10b60029d
  status: UPDATE_FAILED
  status_reason: |
    resources.PreNetworkConfig: Stack UPDATE cancelled
overcloud..Compute.5.PreNetworkConfig:
  resource_type: OS::TripleO::Compute::PreNetworkConfig
  physical_resource_id: 649b473b-8672-414f-853d-3babd04b27d5
  status: CREATE_FAILED
  status_reason: |
    resources.PreNetworkConfig: Stack CREATE cancelled

• /var/log/mistral/engine.log shows the following error:

2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters [req-98da0480-5557-45a6-88e0-37082671add4 a38a5b4d048846128b39700b4913e4bf d4494b6e4cc9489da4ea7fc8520cb2d7 - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1118, u'The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo log size. Increase the redo log size using innodb_log_file_size.') [SQL: u'UPDATE action_executions_v2 SET updated_at=%(updated_at)s, state=%(state)s, accepted=%(accepted)s, output=%(output)s WHERE action_executions_v2.id = %(action_executions_v2_id)s'] [parameters: {'output': '{"result": {"log_path": "/tmp/ansible-mistral-actionRR4ITH/ansible.log", "stderr": "ansible-playbook 2.4.6.0\\n  config file = /usr/share/ceph-ansibl ... (14401211 characters truncated) ... statements should not include jinja2 templating delimiters\\nsuch as {{ }} or {% %}. Found: {{ groups.get(mgr_group_name, []) | length > 0\\n}}\\n"}}', 'state': 'SUCCESS', 'accepted': 1, 'updated_at': datetime.datetime(2019, 4, 10, 18, 8, 23), 'action_executions_v2_id': u'c16c65ee-c482-43a9-a509-f02ccb814596'}] (Background on this error at: http://sqlalche.me/e/2j85): InternalError: (1118, u'The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo log size. Increase the redo log size using innodb_log_file_size.')
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     context)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1118, u'The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo log size. Increase the redo log size using innodb_log_file_size.')
2019-04-10 18:08:24.176 27200 ERROR oslo_db.sqlalchemy.exc_filters 
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server [req-98da0480-5557-45a6-88e0-37082671add4 a38a5b4d048846128b39700b4913e4bf d4494b6e4cc9489da4ea7fc8520cb2d7 - - -] Exception during message handling: DBError: (pymysql.err.InternalError) (1118, u'The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo log size. Increase the redo log size using innodb_log_file_size.') [SQL: u'UPDATE action_executions_v2 SET updated_at=%(updated_at)s, state=%(state)s, accepted=%(accepted)s, output=%(output)s WHERE action_executions_v2.id = %(action_executions_v2_id)s'] [parameters: {'output': '{"result": {"log_path": "/tmp/ansible-mistral-actionRR4ITH/ansible.log", "stderr": "ansible-playbook 2.4.6.0\\n  config file = /usr/share/ceph-ansibl ... (14401211 characters truncated) ... statements should not include jinja2 templating delimiters\\nsuch as {{ }} or {% %}. Found: {{ groups.get(mgr_group_name, []) | length > 0\\n}}\\n"}}', 'state': 'SUCCESS', 'accepted': 1, 'updated_at': datetime.datetime(2019, 4, 10, 18, 8, 23), 'action_executions_v2_id': u'c16c65ee-c482-43a9-a509-f02ccb814596'}] (Background on this error at: http://sqlalche.me/e/2j85)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 157, in on_action_complete
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return self.engine.on_action_complete(action_ex_id, result, wf_action)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 81, in decorate
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return _with_auth_context(auth_ctx, func, *args, **kw)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 214, in wrapped_f
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return self.call(f, *args, **kw)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 295, in call
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     start_time=start_time)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 252, in iter
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return fut.result()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/concurrent/futures/_base.py", line 422, in result
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return self.__get_result()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 298, in call
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = fn(*args, **kwargs)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 50, in _with_auth_context
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return func(*args, **kw)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 95, in decorate
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     res = func(*args, **kw)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 132, in on_action_complete
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     action_handler.on_action_complete(action_ex, result)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/action_handler.py", line 54, in on_action_complete
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     task_handler.schedule_on_action_complete(action_ex)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 449, in schedule_on_action_complete
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     wf_action=isinstance(action_ex, models.WorkflowExecution)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/services/scheduler.py", line 101, in schedule_call
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     db_api.create_delayed_call(values)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/v2/api.py", line 362, in create_delayed_call
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return IMPL.create_delayed_call(values)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/sqlalchemy/base.py", line 117, in _within_session
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = func(*args, **kw)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/v2/sqlalchemy/api.py", line 1001, in create_delayed_call
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     delayed_call.save(session)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     session.flush()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2243, in flush
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     self._flush(objects)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2369, in _flush
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     transaction.rollback(_capture_exception=True)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     compat.reraise(exc_type, exc_value, exc_tb)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2333, in _flush
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     flush_context.execute()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     rec.execute(self)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     uow
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     mapper, table, update)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     execute(statement, multiparams)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 948, in execute
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return meth(self, multiparams, params)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     return connection._execute_clauseelement(self, multiparams, params)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     compiled_sql, distilled_params
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     context)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     util.raise_from_cause(newraise, exc_info)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     context)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     cursor.execute(statement, parameters)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result = self._query(query)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     conn.query(q)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     result.read()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     first_packet = self.connection._read_packet()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     packet.check_error()
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     err.raise_mysql_exception(self._data)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server     raise errorclass(errno, errval)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server DBError: (pymysql.err.InternalError) (1118, u'The size of BLOB/TEXT data inserted in one transaction is greater than 10% of redo log size. Increase the redo log size using innodb_log_file_size.') [SQL: u'UPDATE action_executions_v2 SET updated_at=%(updated_at)s, state=%(state)s, accepted=%(accepted)s, output=%(output)s WHERE action_executions_v2.id = %(action_executions_v2_id)s'] [parameters: {'output': '{"result": {"log_path": "/tmp/ansible-mistral-actionRR4ITH/ansible.log", "stderr": "ansible-playbook 2.4.6.0\\n  config file = /usr/share/ceph-ansibl ... (14401211 characters truncated) ... statements should not include jinja2 templating delimiters\\nsuch as {{ }} or {% %}. Found: {{ groups.get(mgr_group_name, []) | length > 0\\n}}\\n"}}', 'state': 'SUCCESS', 'accepted': 1, 'updated_at': datetime.datetime(2019, 4, 10, 18, 8, 23), 'action_executions_v2_id': u'c16c65ee-c482-43a9-a509-f02ccb814596'}] (Background on this error at: http://sqlalche.me/e/2j85)
2019-04-10 18:08:24.218 27200 ERROR oslo_messaging.rpc.server