[GitHub] [airflow] Squigilum edited a comment on issue #12995: Worker never running tasks or failing them with no explanation for many simultaneous tasks

[GitBox <gi...@apache.org>]

Squigilum edited a comment on issue #12995:
URL: https://github.com/apache/airflow/issues/12995#issuecomment-744655785


   I tried both increasing the allowed connections (from 100 to 250), and enabling pgbouncer, and both still had similar errors.  For pgbouncer, I tried both enabling with the just default parameters and increasing the `maxClientConn` parameter in the chart.  I think I tried 250 and 1000 for the `maxClientConn` parameter. 
   
   I'm attaching the worker logs for my two celery workers.  For this run, tasks 23, 25, and 26 stayed in the queued state and never ran.  23 is active on worker 1 and 25 and 26 are on worker 0.  I've also reduced (from 100 to 40) the amount of concurrent tasks considerably from the DAG I initially shared. 
   
   The only thing I noticed that looked abnormal to me is the following warning in the logs, but it does not seem to occur near the tasks in question:
   ```
   [2020-12-14 18:52:40,054: WARNING/ForkPoolWorker-6] Failed to log action with (psycopg2.DatabaseError) error with status PGRES_TUPLES_OK and no message from the libpq
   (Background on this error at: http://sqlalche.me/e/13/4xp6)
   ```
   
   I'm not sure if I grabbed all the relevant log messages, but the worker logs for the tasks generally look like this:
   ```
   [worker-0.log](https://github.com/apache/airflow/files/5691079/worker-0.log)
   [2020-12-14 18:48:37,531: INFO/MainProcess] Received task: airflow.executors.celery_executor.execute_command[5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d]
   [2020-12-14 18:48:37,532: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7ff0ecd8dc10> (args:('airflow.executors.celery_executor.execute_command', '5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d', {'lang': 'py', 'task': 'airflow.executors.celery_executor.execute_command', 'id': '5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d', 'shadow': None, 'eta': None, 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d', 'parent_id': None, 'argsrepr': "[['airflow', 'tasks', 'run', 'run_100_concurrent', '25', '2020-12-14T18:47:13.448236+00:00', '--local', '--pool', 'default_pool', '--subdir', '/opt/airflow/dags/concurrent_workflow.py']]", 'kwargsrepr': '{}', 'origin': 'gen148@airflow-scheduler-686f8b7b4-2vlrd', 'reply_to': '7a69ddc6-70f1-3417-ae71-92a691da626b', 'correlation_id': '5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d', 'hostname': 'celery@airflow-worker-1', 'delivery_info': {'exchange': '', 'routing_key':
  'celery', 'priority': 0, 'redelivered': None}, 'args': [['airflow', 'tasks', 'run', 'run_100_concurrent', '25',... kwargs:{})
   [2020-12-14 18:48:37,552: DEBUG/MainProcess] Task accepted: airflow.executors.celery_executor.execute_command[5a07e65a-8ad0-4fbe-83c8-8ea952f3a55d] pid:23
   [2020-12-14 18:48:37,750: INFO/ForkPoolWorker-5] Executing command in Celery: ['airflow', 'tasks', 'run', 'run_100_concurrent', '25', '2020-12-14T18:47:13.448236+00:00', '--local', '--pool', 'default_pool', '--subdir', '/opt/airflow/dags/concurrent_workflow.py']
   [2020-12-14 18:48:41,337: DEBUG/ForkPoolWorker-5] Calling callbacks: [<function default_action_log at 0x7ff0efbee5e0>]
   ```
   [worker-0.log](https://github.com/apache/airflow/files/5691087/worker-0.log)
   [worker-1.log](https://github.com/apache/airflow/files/5691089/worker-1.log)
   [scheduler.log](https://github.com/apache/airflow/files/5691090/scheduler.log)
   


----------------------------------------------------------------
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.

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