airflow-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jarek Potiuk (Jira)" <j...@apache.org>
Subject [jira] [Updated] (AIRFLOW-4498) sql metastore/scheduler deadlock
Date Wed, 01 Jan 2020 10:37:00 GMT

     [ https://issues.apache.org/jira/browse/AIRFLOW-4498?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Jarek Potiuk updated AIRFLOW-4498:
----------------------------------
    Attachment: jobs_fixed_deadlock_possibly_1.10.3.py

> sql metastore/scheduler deadlock
> --------------------------------
>
>                 Key: AIRFLOW-4498
>                 URL: https://issues.apache.org/jira/browse/AIRFLOW-4498
>             Project: Apache Airflow
>          Issue Type: Bug
>          Components: database
>    Affects Versions: 1.10.3
>            Reporter: t oo
>            Priority: Major
>         Attachments: jobs_fixed_deadlock_possibly_1.10.3.py
>
>
> see late comments in AIRFLOW-2511, issue still occurring in 1.10.3 release
> 17/Apr/19 14:44
> We're still seeing deadlocking issues within 1.10.3 with this change applied, it appears
that for this specific condition (subdagoperator) it has no effect:
> [2019-04-17 14:01:33,423] {{__init__.py:1580}} ERROR - (_mysql_exceptions.OperationalError)
(1213, 'Deadlock found when trying to get lock; try restarting transaction') [SQL: 'UPDATE
task_instance SET state=%s, queued_dttm=%s WHERE task_instance.task_id = %s AND task_instance.dag_id
= %s AND task_instance.execution_date = %s'] [parameters: ('queued', datetime.datetime(2019,
4, 17, 14, 1, 18, 249580, tzinfo=<Timezone [UTC]>), 'subdag_task_instance', 'subdag_dag.move_data',
datetime.datetime(2019, 4, 17, 11, 35, 56, 625793, tzinfo=<Timezone [UTC]>))] (Background
on this error at: http://sqlalche.me/e/e3q8)
> Traceback (most recent call last):
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1236, in
_execute_context
>     cursor, statement, parameters, context
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 536, in
do_execute
>     cursor.execute(statement, parameters)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 255, in execute
>     self.errorhandler(self, exc, value)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 50, in defaulterrorhandler
>     raise errorvalue
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 252, in execute
>     res = self._query(query)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 378, in _query
>     db.query(q)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 280, in query
>     _mysql.connection.query(self, query)
> _mysql_exceptions.OperationalError: (1213, 'Deadlock found when trying to get lock; try
restarting transaction')
> The above exception was the direct cause of the following exception:
> Traceback (most recent call last):
>   File "/usr/lib/python3.6/site-packages/airflow/models/__init__.py", line 1441, in _run_raw_task
>     result = task_copy.execute(context=context)
>   File "/usr/lib/python3.6/site-packages/airflow/operators/subdag_operator.py", line
102, in execute
>     executor=self.executor)
>   File "/usr/lib/python3.6/site-packages/airflow/models/__init__.py", line 4030, in run
>     job.run()
>   File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 209, in run
>     self._execute()
>   File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 73, in wrapper
>     return func(*args, **kwargs)
>   File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2475, in _execute
>     session=session)
>   File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 69, in wrapper
>     return func(*args, **kwargs)
>   File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2421, in _execute_for_run_dates
>     session=session)
>   File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 69, in wrapper
>     return func(*args, **kwargs)
>   File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2310, in _process_backfill_task_instances
>     _per_task_process(task, key, ti)
>   File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 73, in wrapper
>     return func(*args, **kwargs)
>   File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2273, in _per_task_process
>     session.commit()
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1023, in
commit
>     self.transaction.commit()
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 487, in commit
>     self._prepare_impl()
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 466, in _prepare_impl
>     self.session.flush()
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2446, in
flush
>     self._flush(objects)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2584, in
_flush
>     transaction.rollback(_capture_exception=True)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 67,
in __exit__
>     compat.reraise(exc_type, exc_value, exc_tb)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 277, in reraise
>     raise value
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2544, in
_flush
>     flush_context.execute()
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 416, in
execute
>     rec.execute(self)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 583, in
execute
>     uow,
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 236,
in save_obj
>     update,
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 976,
in _emit_update_statements
>     statement, multiparams
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 980, in execute
>     return meth(self, multiparams, params)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/elements.py", line 273, in
_execute_on_connection
>     return connection._execute_clauseelement(self, multiparams, params)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1099, in
_execute_clauseelement
>     distilled_params,
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1240, in
_execute_context
>     e, statement, parameters, cursor, context
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1458, in
_handle_dbapi_exception
>     util.raise_from_cause(sqlalchemy_exception, exc_info)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 296, in raise_from_cause
>     reraise(type(exception), exception, tb=exc_tb, cause=cause)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 276, in reraise
>     raise value.with_traceback(tb)
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1236, in
_execute_context
>     cursor, statement, parameters, context
>   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 536, in
do_execute
>     cursor.execute(statement, parameters)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 255, in execute
>     self.errorhandler(self, exc, value)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 50, in defaulterrorhandler
>     raise errorvalue
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 252, in execute
>     res = self._query(query)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 378, in _query
>     db.query(q)
>   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 280, in query
>     _mysql.connection.query(self, query)
> sqlalchemy.exc.OperationalError: (_mysql_exceptions.OperationalError) (1213, 'Deadlock
found when trying to get lock; try restarting transaction') [SQL: 'UPDATE task_instance SET
state=%s, queued_dttm=%s WHERE task_instance.task_id = %s AND task_instance.dag_id = %s AND
task_instance.execution_date = %s'] [parameters: ('queued', datetime.datetime(2019, 4, 17,
14, 1, 18, 249580, tzinfo=<Timezone [UTC]>), 'subdag_task_instance', 'subdag_dag.move_data',
datetime.datetime(2019, 4, 17, 11, 35, 56, 625793, tzinfo=<Timezone [UTC]>))] (Background
on this error at: http://sqlalche.me/e/e3q8)
> [2019-04-17 14:01:33,437] {{__init__.py:1611}} INFO - Marking task as FAILED.
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
Traceback (most recent call last):
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1236, in _execute_context
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    cursor, statement, parameters, context
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 536, in do_execute
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    cursor.execute(statement, parameters)
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 255, in execute
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self.errorhandler(self, exc, value)
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 50, in defaulterrorhandler
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    raise errorvalue
> [2019-04-17 14:01:33,733] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 252, in execute
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    res = self._query(query)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 378, in _query
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    db.query(q)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 280, in query
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    _mysql.connection.query(self, query)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
_mysql_exceptions.OperationalError: (1213, 'Deadlock found when trying to get lock; try restarting
transaction')
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data

> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
The above exception was the direct cause of the following exception:
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data

> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
Traceback (most recent call last):
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/bin/airflow", line 32, in <module>
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    args.func(args)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/cli.py", line 74, in wrapper
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return f(*args, **kwargs)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/bin/cli.py", line 523, in run
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    _run(args, dag, ti)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/bin/cli.py", line 442, in _run
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    pool=args.pool,
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 73, in wrapper
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return func(*args, **kwargs)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/models/__init__.py", line 1441, in _run_raw_task
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    result = task_copy.execute(context=context)
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/operators/subdag_operator.py", line 102,
in execute
> [2019-04-17 14:01:33,734] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    executor=self.executor)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/models/__init__.py", line 4030, in run
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    job.run()
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 209, in run
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self._execute()
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 73, in wrapper
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return func(*args, **kwargs)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2475, in _execute
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    session=session)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 69, in wrapper
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return func(*args, **kwargs)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2421, in _execute_for_run_dates
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    session=session)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 69, in wrapper
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return func(*args, **kwargs)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2310, in _process_backfill_task_instances
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    _per_task_process(task, key, ti)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/utils/db.py", line 73, in wrapper
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return func(*args, **kwargs)
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib/python3.6/site-packages/airflow/jobs.py", line 2273, in _per_task_process
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    session.commit()
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1023, in commit
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self.transaction.commit()
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 487, in commit
> [2019-04-17 14:01:33,735] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self._prepare_impl()
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 466, in _prepare_impl
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self.session.flush()
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2446, in flush
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self._flush(objects)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2584, in _flush
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    transaction.rollback(_capture_exception=True)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 67, in __exit__
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    compat.reraise(exc_type, exc_value, exc_tb)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 277, in reraise
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    raise value
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2544, in _flush
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    flush_context.execute()
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 416, in execute
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    rec.execute(self)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 583, in execute
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    uow,
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 236, in save_obj
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    update,
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 976, in _emit_update_statements
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    statement, multiparams
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 980, in execute
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return meth(self, multiparams, params)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/elements.py", line 273, in _execute_on_connection
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    return connection._execute_clauseelement(self, multiparams, params)
> [2019-04-17 14:01:33,736] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1099, in _execute_clauseelement
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    distilled_params,
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1240, in _execute_context
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    e, statement, parameters, cursor, context
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1458, in _handle_dbapi_exception
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    util.raise_from_cause(sqlalchemy_exception, exc_info)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 296, in raise_from_cause
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 276, in reraise
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    raise value.with_traceback(tb)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1236, in _execute_context
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    cursor, statement, parameters, context
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 536, in do_execute
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    cursor.execute(statement, parameters)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 255, in execute
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    self.errorhandler(self, exc, value)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 50, in defaulterrorhandler
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    raise errorvalue
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 252, in execute
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    res = self._query(query)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 378, in _query
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    db.query(q)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
  File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 280, in query
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
    _mysql.connection.query(self, query)
> [2019-04-17 14:01:33,737] {{base_task_runner.py:101}} INFO - Job 942670: Subtask move_data
sqlalchemy.exc.OperationalError: (_mysql_exceptions.OperationalError) (1213, 'Deadlock found
when trying to get lock; try restarting transaction') [SQL: 'UPDATE task_instance SET state=%s,
queued_dttm=%s WHERE task_instance.task_id = %s AND task_instance.dag_id = %s AND task_instance.execution_date
= %s'] [parameters: ('queued', datetime.datetime(2019, 4, 17, 14, 1, 18, 249580, tzinfo=<Timezone
[UTC]>), 'subdag_task_instance', 'subdag_dag.move_data', datetime.datetime(2019, 4, 17,
11, 35, 56, 625793, tzinfo=<Timezone [UTC]>))] (Background on this error at: http://sqlalche.me/e/e3q8)
> [2019-04-17 14:01:34,250] {{logging_mixin.py:95}} INFO - [2019-04-17 14:01:34,249] {{jobs.py:2562}}
INFO - Task exited with return code 1
> Permalink
> jbonjean Julien Bonjean added a comment - 4 days ago
> I can see the exact same issue in 1.10.3, but with BranchPythonOperator and DockerOperator.
> Permalink Edit Delete
> toopt4 t oo added a comment - 3 days ago
> still getting this issue in 1.10.3!



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Mime
View raw message