Airflow错误邮件中Exception行无错误信息的原因排查

问题背景 #

使用Airflow的DockerOperator执行任务时，任务日志里能看到容器内的具体错误信息，但错误告警邮件仅显示Docker container failed: {'StatusCode': 1}，无法直接看到实际报错内容。尝试过设置tty=True和tty=False，问题仍未解决。

告警邮件内容 #

Try 1 out of 1
Exception:
Docker container failed: {'StatusCode': 1}
Log: Link
Host: dba97f6f685a
Mark success: Link

任务日志内容 #

dba97f6f685a
*** Found local files:
***   * /opt/airflow/logs/dag_id=my_dag/run_id=manual__2024-02-13T16:38:33.841697+00:00/task_id=my_task/attempt=1.log
[2024-02-13, 13:38:35 -03] {taskinstance.py:1956} INFO - Dependencies all met for dep_context=non-requeueable deps ti=<TaskInstance: my_dag.my_task manual__2024-02-13T16:38:33.841697+00:00 [queued]>
[2024-02-13, 13:38:35 -03] {taskinstance.py:1956} INFO - Dependencies all met for dep_context=requeueable deps ti=<TaskInstance: my_dag.my_task manual__2024-02-13T16:38:33.841697+00:00 [queued]>
[2024-02-13, 13:38:35 -03] {taskinstance.py:2170} INFO - Starting attempt 1 of 1
[2024-02-13, 13:38:35 -03] {taskinstance.py:2191} INFO - Executing <Task(DockerOperator): my_task> on 2024-02-13 16:38:33.841697+00:00
[2024-02-13, 13:38:35 -03] {standard_task_runner.py:60} INFO - Started process 908 to run task
[2024-02-13, 13:38:35 -03] {standard_task_runner.py:87} INFO - Running: ['***', 'tasks', 'run', 'my_dag', 'my_task', 'manual__2024-02-13T16:38:33.841697+00:00', '--job-id', '2913', '--raw', '--subdir', 'DAGS_FOLDER/project_***_dags/***/dags/config/test/test.py', '--cfg-path', '/tmp/tmpus3spbk2']
[2024-02-13, 13:38:35 -03] {standard_task_runner.py:88} INFO - Job 2913: Subtask my_task
[2024-02-13, 13:38:35 -03] {task_command.py:423} INFO - Running <TaskInstance: my_dag.my_task manual__2024-02-13T16:38:33.841697+00:00 [running]> on host dba97f6f685a
[2024-02-13, 13:38:36 -03] {taskinstance.py:2480} INFO - Exporting env vars: AIRFLOW_CTX_DAG_EMAIL='account@company.com' AIRFLOW_CTX_DAG_OWNER='Data Engineering' AIRFLOW_CTX_DAG_ID='my_dag' AIRFLOW_CTX_TASK_ID='my_task' AIRFLOW_CTX_EXECUTION_DATE='2024-02-13T16:38:33.841697+00:00' AIRFLOW_CTX_TRY_NUMBER='1' AIRFLOW_CTX_DAG_RUN_ID='manual__2024-02-13T16:38:33.841697+00:00'
[2024-02-13, 13:38:36 -03] {docker.py:359} INFO - Starting docker container from image crcompanyde.azurecr.io/app_general_python:1.0.0
[2024-02-13, 13:38:36 -03] {docker.py:429} INFO - Traceback (most recent call last):
  File "/usr/src/app2/test/test.py", line 6, in <module>
    raise Exception("Sorry, no numbers below zero")
Exception: Sorry, no numbers below zero
[2024-02-13, 13:38:36 -03] {docker.py:429} INFO - 2024-02-13 16:38:36.280714 Start
[2024-02-13, 13:38:36 -03] {taskinstance.py:2698} ERROR - Task failed with exception
Traceback (most recent call last):
  File "/home/airflow/.local/lib/python3.8/site-packages/airflow/models/taskinstance.py", line 433, in _execute_task
    result = execute_callable(context=context, **execute_callable_kwargs)
  File "/home/airflow/.local/lib/python3.8/site-packages/airflow/providers/docker/operators/docker.py", line 502, in execute
    return self._run_image()
  File "/home/airflow/.local/lib/python3.8/site-packages/airflow/providers/docker/operators/docker.py", line 376, in _run_image
    return self._run_image_with_mounts(self.mounts, add_tmp_variable=False)
  File "/home/airflow/.local/lib/python3.8/site-packages/airflow/providers/docker/operators/docker.py", line 437, in _run_image_with_mounts
    raise DockerContainerFailedException(f"Docker container failed: {result!r}", logs=log_lines)
airflow.providers.docker.exceptions.DockerContainerFailedException: Docker container failed: {'StatusCode': 1}
[2024-02-13, 13:38:36 -03] {taskinstance.py:1138} INFO - Marking task as FAILED. dag_id=my_dag, task_id=my_task, execution_date=20240213T163833, start_date=20240213T163835, end_date=20240213T163836
[2024-02-13, 13:38:36 -03] {crypto.py:82} WARNING - empty cryptography key - values will not be stored encrypted.
[2024-02-13, 13:38:36 -03] {base.py:83} INFO - Using connection ID 'smtp_default' for task execution.
[2024-02-13, 13:38:36 -03] {email.py:270} INFO - Email alerting: attempt 1
[2024-02-13, 13:38:37 -03] {email.py:281} INFO - Sent an alert email to ['account@company.com']
[2024-02-13, 13:38:37 -03] {standard_task_runner.py:107} ERROR - Failed to execute job 2913 for task my_task (Docker container failed: {'StatusCode': 1}; 908)
[2024-02-13, 13:38:37 -03] {local_task_job_runner.py:234} INFO - Task exited with return code 1
[2024-02-13, 13:38:37 -03] {taskinstance.py:3280} INFO - 0 downstream tasks scheduled from follow-on schedule check

排查思路 #

• 修改Airflow邮件告警模板：默认邮件模板未提取DockerContainerFailedException携带的logs参数内容，需自定义模板，在异常信息部分添加对异常对象logs属性的渲染，将容器内日志纳入邮件内容。
• 确认DockerOperator日志传递逻辑：检查当前Airflow版本中DockerOperator的实现，确认log_lines是否正确传入异常。从现有日志看，异常抛出时已携带logs=log_lines，问题核心在邮件模板的渲染逻辑。
• 自定义告警回调逻辑：若模板修改繁琐，可通过on_failure_callback回调函数捕获异常，自行组装包含容器日志的告警内容，调用邮件接口发送。
• 升级DockerProvider版本：部分旧版本apache-airflow-providers-docker存在邮件未传递容器日志的bug，升级到最新稳定版可尝试修复该问题。
• 验证容器日志输出流：DockerOperator仅捕获容器的标准输出/错误流，若容器内日志写入文件而非控制台，需修改程序配置，将日志重定向到stdout/stderr。

内容的提问来源于stack exchange，提问作者fCotrim