Attachment 1459739 Details for Bug 1602840 – mistral engine.log errors

mistral engine.log errors

mistral-error.txt (text/plain), 18.19 KB, created by Keith Schincke on 2018-07-18 15:30:25 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Keith Schincke

Created: 2018-07-18 15:30:25 UTC

Size: 18.19 KB

patch

obsolete

>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters [req-efbee4d1-6bc4-4296-a9eb-b7487769f03f 8ede70cba5864237ae1837b7a038783d 120e4ca72c7b4ef58b84c54d40f83480 - default defau
>lt] 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-actionZpGRKz/ansible.log", "stderr": "ansible-playbook 2.4.3.0\\n  config file = /usr/s
>hare/ceph-ansibl ... (12029351 characters truncated) ... statements should not include jinja2 templating delimiters\\nsuch as {{ }} or {% %}. Found: {{ groups.get(mgr_group_name, []) | lengt
>h > 0\\n}}\\n"}}', 'state': 'SUCCESS', 'accepted': 1, 'updated_at': datetime.datetime(2018, 7, 18, 12, 52, 8), 'action_executions_v2_id': u'6ff656d4-e0d8-44df-875c-8e81245ecbb4'}] (Backgroun
>d 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.')
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     context)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
>2018-07-18 07:52:09.771 32570 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.')
>2018-07-18 07:52:09.771 32570 ERROR oslo_db.sqlalchemy.exc_filters 
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server [req-efbee4d1-6bc4-4296-a9eb-b7487769f03f 8ede70cba5864237ae1837b7a038783d 120e4ca72c7b4ef58b84c54d40f83480 - default default] E
>xception 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_v
>2.id = %(action_executions_v2_id)s'] [parameters: {'output': '{"result": {"log_path": "/tmp/ansible-mistral-actionZpGRKz/ansible.log", "stderr": "ansible-playbook 2.4.3.0\\n  config file = /
>usr/share/ceph-ansibl ... (12029351 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(2018, 7, 18, 12, 52, 8), 'action_executions_v2_id': u'6ff656d4-e0d8-44df-875c-8e81245ecbb4'}] (Background on this error at: http://sqlalche.me/e/2j85)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 157, in on_action_complete
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return self.engine.on_action_complete(action_ex_id, result, wf_action)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 81, in decorate
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return _with_auth_context(auth_ctx, func, *args, **kw)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 214, in wrapped_f
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return self.call(f, *args, **kw)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 295, in call
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     start_time=start_time)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 252, in iter
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return fut.result()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/concurrent/futures/_base.py", line 422, in result
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return self.__get_result()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 298, in call
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = fn(*args, **kwargs)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 50, in _with_auth_context
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return func(*args, **kw)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 95, in decorate
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     res = func(*args, **kw)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 132, in on_action_complete
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     action_handler.on_action_complete(action_ex, result)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/action_handler.py", line 54, in on_action_complete
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     task_handler.schedule_on_action_complete(action_ex)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 449, in schedule_on_action_complete
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     wf_action=isinstance(action_ex, models.WorkflowExecution)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/services/scheduler.py", line 101, in schedule_call
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     db_api.create_delayed_call(values)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/v2/api.py", line 358, in create_delayed_call
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return IMPL.create_delayed_call(values)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/sqlalchemy/base.py", line 117, in _within_session
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = func(*args, **kw)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/mistral/db/v2/sqlalchemy/api.py", line 996, in create_delayed_call
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     delayed_call.save(session)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     session.flush()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2243, in flush
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     self._flush(objects)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2369, in _flush
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     transaction.rollback(_capture_exception=True)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     compat.reraise(exc_type, exc_value, exc_tb)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2333, in _flush
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     flush_context.execute()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     rec.execute(self)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     uow
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     mapper, table, update)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     execute(statement, multiparams)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 948, in execute
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return meth(self, multiparams, params)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     return connection._execute_clauseelement(self, multiparams, params)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     compiled_sql, distilled_params
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     context)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     util.raise_from_cause(newraise, exc_info)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     reraise(type(exception), exception, tb=exc_tb, cause=cause)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     context)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     cursor.execute(statement, parameters)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result = self._query(query)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     conn.query(q)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     result.read()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     first_packet = self.connection._read_packet()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     packet.check_error()
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     err.raise_mysql_exception(self._data)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server     raise errorclass(errno, errval)
>2018-07-18 07:52:09.838 32570 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-actionZpGRKz/ansible.log", "stderr": "ansible-playbook 2.4.3.0\\n  config file = /usr/share/ceph-ansibl ... (12029351 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(2018, 7, 18, 12, 52, 8), 'action_executions_v2_id': u'6ff656d4-e0d8-44df-875c-8e81245ecbb4'}] (Background on this error at: http://sqlalche.me/e/2j85)
>2018-07-18 07:52:09.838 32570 ERROR oslo_messaging.rpc.server

Actions: View

Attachments on bug 1602840: 1459739