使用Kubernetes Executor的Airflow任务超5分钟被SIGTERM终止求助

通过Bitnami Helm Chart在Kubernetes集群部署了采用Kubernetes Executor的Airflow实例，当执行耗时超过5分钟的任务时，Scheduler会自动终止任务，已尝试相关方案但未解决，日志信息如下：

调度器日志 #

[2022-08-05 18:27:20,117] {kubernetes_executor.py:147} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e had an event of type MODIFIED
[2022-08-05 18:27:20,118] {kubernetes_executor.py:213} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e is Running
[2022-08-05 18:27:38,908] {kubernetes_executor.py:454} INFO - Found 0 queued task instances
[2022-08-05 18:28:39,212] {kubernetes_executor.py:454} INFO - Found 0 queued task instances
[2022-08-05 18:29:39,394] {kubernetes_executor.py:454} INFO - Found 0 queued task instances
[2022-08-05 18:30:39,575] {kubernetes_executor.py:454} INFO - Found 0 queued task instances
[2022-08-05 18:31:39,766] {kubernetes_executor.py:454} INFO - Found 0 queued task instances
[2022-08-05 18:32:10,603] {kubernetes_executor.py:147} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e had an event of type MODIFIED
[2022-08-05 18:32:10,603] {kubernetes_executor.py:213} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e is Running
[2022-08-05 18:32:11,436] {kubernetes_executor.py:147} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e had an event of type MODIFIED
[2022-08-05 18:32:11,436] {kubernetes_executor.py:206} INFO - Event: process1800.404b6cc740064e90955e28dd736f899e Succeeded
[2022-08-05 18:32:11,943] {kubernetes_executor.py:374} INFO - Attempting to finish pod; pod_id: process1800.404b6cc740064e90955e28dd736f899e; state: None; annotations: {'dag_id': 'kubernetes_pod', 'task_id': 'process1800', 'execution_date': None, 'run_id': 'manual__2022-08-05T18:26:58.893963+00:00', 'try_number': '1'}

Worker日志 #

/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/configuration.py:357 DeprecationWarning: The base_log_folder option in [core] has been moved to the base_log_folder option in [logging] - the old setting has been used, but please update your config.
[2022-08-05 18:27:20,359] {dagbag.py:500} INFO - Filling up the DagBag from /opt/bitnami/airflow/dags/git_dataextractor-dag/docker_scraplimit.py
/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/kubernetes/volume.py:22 DeprecationWarning: This module is deprecated. Please use `kubernetes.client.models.V1Volume`.
/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/kubernetes/volume_mount.py:22 DeprecationWarning: This module is deprecated. Please use `kubernetes.client.models.V1VolumeMount`.
Running <TaskInstance: kubernetes_pod.process1800 manual__2022-08-05T18:26:58.893963+00:00 [queued]> on host process1800.404b6cc740064e90955

Process finished with exit code 0

任务日志 #

[2022-08-05, 18:32:09 UTC] {local_task_job.py:82} ERROR - Received SIGTERM. Terminating subprocesses
[2022-08-05, 18:32:09 UTC] {process_utils.py:120} INFO - Sending Signals.SIGTERM to group 18. PIDs of all processes in the group: [18]
[2022-08-05, 18:32:09 UTC] {process_utils.py:75} INFO - Sending the signal Signals.SIGTERM to group 18
[2022-08-05, 18:32:09 UTC] {taskinstance.py:1430} ERROR - Received SIGTERM. Terminating subprocesses.
[2022-08-05, 18:32:09 UTC] {kubernetes_pod.py:459} INFO - Deleting pod: airflow-yield-datalayer.7859414c89794502b683608a386a819c
[2022-08-05, 18:32:09 UTC] {taskinstance.py:1774} ERROR - Task failed with exception
Traceback (most recent call last):
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/providers/cncf/kubernetes/operators/kubernetes_pod.py", line 417, in execute
    self.pod_manager.follow_container_logs(
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/providers/cncf/kubernetes/utils/pod_manager.py", line 208, in follow_container_logs
    last_log_time = follow_logs(since_time=last_log_time)
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/providers/cncf/kubernetes/utils/pod_manager.py", line 195, in follow_logs
    for line in logs:  # type: bytes
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/urllib3/response.py", line 811, in __iter__
    for chunk in self.stream(decode_content=True):
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/urllib3/response.py", line 575, in stream
    for line in self.read_chunked(amt, decode_content=decode_content):
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/urllib3/response.py", line 767, in read_chunked
    self._update_chunk_length()
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/urllib3/response.py", line 697, in _update_chunk_length
    line = self._fp.fp.readline()
  File "/opt/bitnami/python/lib/python3.8/socket.py", line 669, in readinto
    return self._sock.recv_into(b)
  File "/opt/bitnami/python/lib/python3.8/ssl.py", line 1241, in recv_into
    return self.read(nbytes, buffer)
  File "/opt/bitnami/python/lib/python3.8/ssl.py", line 1099, in read
    return self._sslobj.read(len, buffer)
  File "/opt/bitnami/airflow/venv/lib/python3.8/site-packages/airflow/models/taskinstance.py", line 1432, in signal_handler
    raise AirflowException("Task received SIGTERM signal")
airflow.exceptions.AirflowException: Task received SIGTERM signal

解决方向 #

1. 调整Pod探针配置 #

Bitnami默认Helm配置可能给Worker Pod设置了过短的存活/就绪探针参数，若长任务长时间无日志输出，探针会判定Pod不健康并触发终止：

• 修改Helm values中的workers.livenessProbe和workers.readinessProbe，延长initialDelaySeconds、periodSeconds，提高failureThreshold；
• 检查KubernetesPodOperator启动的子Pod探针配置，避免因无输出被K8s终止。

2. 修正任务超时参数 #

• 确认core.dag_run_timeout及单个任务的execution_timeout设置，确保超时时长大于任务实际运行时间；
• 检查Kubernetes Executor的kubernetes.pod_template_file中是否设置了activeDeadlineSeconds，该参数会强制终止超时Pod。

3. 修复日志流中断问题 #

任务日志显示读取K8s日志时触发SIGTERM，可能是日志连接超时导致：

• 在KubernetesPodOperator中设置get_logs=False，停止Airflow实时跟踪子Pod日志，改为事后查看；
• 调整Airflow配置中的kubernetes.request_timeout参数，延长K8s API请求超时时间。

4. 检查Scheduler相关配置 #

排查Bitnami Chart中Scheduler的airflow.scheduler.kubernetes_executor参数，确认无强制终止长任务的配置项。

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