You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@airflow.apache.org by GitBox <gi...@apache.org> on 2021/07/11 09:16:51 UTC

[GitHub] [airflow] vapiravfif commented on issue #16023: Running tasks marked as 'orphaned' and killed by scheduler

vapiravfif commented on issue #16023:
URL: https://github.com/apache/airflow/issues/16023#issuecomment-877767772


   @Jorricks Hi, it might be helpful to know that I couldn't reproduce the issue on a DAG that was previously active, but it reproduced like a charm on a brand new DAG with same setup. Both paused at the time of running the tasks.
   
   I can't find anything related to either `Setting external_id for` or `SchedulerJob instances as failed` in the logs for both instances (on DEBUG)
   
   Here's a `grep -A 5 -B 5` from logs related to the task name (there wasn't related logs on webserver...):
   ```
   Scheduler:
   [2021-07-11 08:28:08,961] {dag_processing.py:385} DEBUG - Received message of type DagParsingStat
   [2021-07-11 08:28:08,972] {scheduler_job.py:1854} INFO - Resetting orphaned tasks for active dag runs
   [2021-07-11 08:28:08,972] {scheduler_job.py:1862} DEBUG - Running SchedulerJob.adopt_or_reset_orphaned_tasks with retries. Try 1 of 3
   [2021-07-11 08:28:08,972] {scheduler_job.py:1864} DEBUG - Calling SchedulerJob.adopt_or_reset_orphaned_tasks method
   [2021-07-11 08:28:09,003] {scheduler_job.py:1921} INFO - Reset the following 1 orphaned TaskInstances:
       <TaskInstance: timeout_testing.sleep_operator_task 2021-07-11 08:02:31.293769+00:00 [running]>
   [2021-07-11 08:28:09,020] {scheduler_job.py:1399} DEBUG - Next timed event is in 0.645959
   [2021-07-11 08:28:09,020] {scheduler_job.py:1401} DEBUG - Ran scheduling loop in 0.13 seconds
   [2021-07-11 08:28:09,205] {settings.py:292} DEBUG - Disposing DB connection pool (PID 1178)
   [2021-07-11 08:28:09,223] {scheduler_job.py:310} DEBUG - Waiting for <ForkProcess(DagFileProcessor921-Process, stopped)>
   [2021-07-11 08:28:09,469] {settings.py:292} DEBUG - Disposing DB connection pool (PID 1182)
   
   
   Worker:
   [2021-07-11 08:23:47,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:23:52,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:23:57,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:02,558: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:07,132: INFO/MainProcess] Received task: airflow.executors.celery_executor.execute_command[ad28b4dc-6a78-4821-9a02-998aff8156b2]  
   [2021-07-11 08:24:07,133: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7feff474d3b0> (args:('airflow.executors.celery_executor.execute_command', 'ad28b4dc-6a78-4821-9a02-998aff8156b2', {'lang': 'py', 'task': 'airflow.executors.celery_executor.execute_command', 'id': 'ad28b4dc-6a78-4821-9a02-998aff8156b2', 'shadow': None, 'eta': None, 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': 'ad28b4dc-6a78-4821-9a02-998aff8156b2', 'parent_id': None, 'argsrepr': "[['airflow', 'tasks', 'run', 'timeout_testing', 'sleep_operator_task', '2021-07-11T08:02:31.293769+00:00', '--local', '--pool', 'default_pool', '--subdir', 'DAGS_FOLDER/timeout_testing.py']]", 'kwargsrepr': '{}', 'origin': 'gen268@airflow-dev-web-6d79645c68-tzbnv', 'reply_to': 'a3aa91fd-479b-3d76-893e-7a8e8d23c454', 'correlation_id': 'ad28b4dc-6a78-4821-9a02-998aff8156b2', 'hostname': 'celery@airflow-dev-worker-0', 'delivery_info': {'exchange': '', 'routin
 g_key': 'default', 'priority': 0, 'redelivered': None}, 'args': [['airflow', 'tasks', 'run', 'timeout_testing', 'sleep_operator_task',... kwargs:{})
   [2021-07-11 08:24:07,134: DEBUG/MainProcess] Task accepted: airflow.executors.celery_executor.execute_command[ad28b4dc-6a78-4821-9a02-998aff8156b2] pid:45
   --
   [2021-07-11 08:24:07,134: DEBUG/MainProcess] Task accepted: airflow.executors.celery_executor.execute_command[ad28b4dc-6a78-4821-9a02-998aff8156b2] pid:45
   [2021-07-11 08:24:07,186: INFO/ForkPoolWorker-15] Executing command in Celery: ['airflow', 'tasks', 'run', 'timeout_testing', 'sleep_operator_task', '2021-07-11T08:02:31.293769+00:00', '--local', '--pool', 'default_pool', '--subdir', 'DAGS_FOLDER/timeout_testing.py']
   [2021-07-11 08:24:07,329: DEBUG/ForkPoolWorker-15] Calling callbacks: [<function default_action_log at 0x7ff0008deb90>]
   [2021-07-11 08:24:07,350: DEBUG/ForkPoolWorker-15] Setting up DB connection pool (PID 47)
   [2021-07-11 08:24:07,351: DEBUG/ForkPoolWorker-15] settings.prepare_engine_args(): Using NullPool
   [2021-07-11 08:24:07,353: INFO/ForkPoolWorker-15] Filling up the DagBag from ...dags_dev/timeout_testing.py
   [2021-07-11 08:24:07,354: DEBUG/ForkPoolWorker-15] Importing ...dags_dev/timeout_testing.py
   --
   --
   [2021-07-11 08:24:07,357: DEBUG/ForkPoolWorker-15] Loaded DAG <DAG: timeout_testing>
   [2021-07-11 08:24:07,399: DEBUG/ForkPoolWorker-15] Loading plugins
   [2021-07-11 08:24:07,399: DEBUG/ForkPoolWorker-15] Loading plugins from directory: /opt/airflow/plugins
   [2021-07-11 08:24:07,399: DEBUG/ForkPoolWorker-15] Loading plugins from entrypoints
   [2021-07-11 08:24:07,473: DEBUG/ForkPoolWorker-15] Integrate DAG plugins
   [2021-07-11 08:24:07,501: WARNING/ForkPoolWorker-15] Running <TaskInstance: timeout_testing.sleep_operator_task 2021-07-11T08:02:31.293769+00:00 [None]> on host airflow-dev-worker-0.airflow-dev-worker.airflow-dev.svc.cluster.local
   [2021-07-11 08:24:07,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:12,562: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:17,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:22,563: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   [2021-07-11 08:24:27,559: DEBUG/MainProcess] pidbox received method enable_events() [reply_to:None ticket:None]
   --
   ```
   
   I cannot share the full logs as I'm testing in real environment and there are many S3 requests that need hashing, but I saved the logs and happy to provide any part of them as needed. Thank you!


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org