tanvn commented on issue #39088:
URL: https://github.com/apache/airflow/issues/39088#issuecomment-2072822564
@RNHTTR
Tested and reproduced the issue on Airflow 2.8.4, below is the error logs
from scheduler and one terminated pod
```
2024-04-23T15:56:15.805+0000] {task_context_logger.py:63} INFO - Task
context logging is enabled
[2024-04-23T15:56:15.806+0000] {executor_loader.py:115} INFO - Loaded
executor: KubernetesExecutor
/usr/local/lib/python3.10/site-packages/airflow/providers/cncf/kubernetes/executors/kubernetes_executor.py:165
FutureWarning: The config section [kubernetes] has been renamed to
[kubernetes_executor]. Please update your `conf.get*` call to use the new name
[2024-04-23T15:56:16.000+0000] {scheduler_job_runner.py:807} INFO - Starting
the scheduler
[2024-04-23T15:56:16.002+0000] {scheduler_job_runner.py:814} INFO -
Processing each file at most -1 times
[2024-04-23T15:56:16.004+0000] {kubernetes_executor.py:318} INFO - Start
Kubernetes executor
[2024-04-23T15:56:16.091+0000] {kubernetes_executor_utils.py:157} INFO -
Event: and now my watch begins starting at resource_version: 0
[2024-04-23T15:56:16.118+0000] {kubernetes_executor.py:239} INFO - Found 0
queued task instances
[2024-04-23T15:56:16.194+0000] {manager.py:169} INFO - Launched
DagFileProcessorManager with pid: 34
[2024-04-23T15:56:16.196+0000] {scheduler_job_runner.py:1607} INFO -
Adopting or resetting orphaned tasks for active dag runs
[2024-04-23T15:56:16.207+0000] {settings.py:60} INFO - Configured default
timezone UTC
[2024-04-23T15:56:16.301+0000] {settings.py:541} INFO - Loaded
airflow_local_settings from /opt/airflow/config/airflow_local_settings.py .
172.32.255.100 - - [23/Apr/2024 15:56:16] "GET /health HTTP/1.1" 200 -
[2024-04-23T15:56:17.186+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-25-0akkpbca
[2024-04-23T15:56:17.392+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-26-v3hdab2d
[2024-04-23T15:56:17.397+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-25-0akkpbca is Running, annotations:
<omitted>
[2024-04-23T15:56:17.590+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-26-v3hdab2d is Running, annotations:
<omitted>
[2024-04-23T15:56:17.591+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-27-3fgog69m
172.32.212.113 - - [23/Apr/2024 15:56:17] "GET /health HTTP/1.1" 200 -
[2024-04-23T15:56:17.785+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-28-12d0e5k3
[2024-04-23T15:56:17.791+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-27-3fgog69m is Running, annotations:
<omitted>
[2024-04-23T15:56:17.988+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-29-nyli4xns
[2024-04-23T15:56:17.992+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-28-12d0e5k3 is Running, annotations:
<omitted>
[2024-04-23T15:56:18.184+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-29-nyli4xns is Running, annotations:
<omitted>
[2024-04-23T15:56:18.193+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-3-rrdebytu
[2024-04-23T15:56:18.383+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-32-bce8olgk
[2024-04-23T15:56:18.385+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-3-rrdebytu is Running, annotations:
<omitted>
[2024-04-23T15:56:18.501+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-32-bce8olgk is Running, annotations:
<omitted>
[2024-04-23T15:56:18.589+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-56-uf9tmjkr
[2024-04-23T15:56:18.701+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-56-uf9tmjkr is Running, annotations:
<omitted>
[2024-04-23T15:56:18.797+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-57-sgtmtbw9
[2024-04-23T15:56:18.987+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-57-sgtmtbw9 is Running, annotations:
<omitted>
[2024-04-23T15:56:18.988+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-59-24yyhobe
[2024-04-23T15:56:19.102+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-6-aj680tdg
[2024-04-23T15:56:19.195+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-59-24yyhobe is Running, annotations:
<omitted>
[2024-04-23T15:56:19.284+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-60-3vx8m1ak
[2024-04-23T15:56:19.297+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-6-aj680tdg is Running, annotations:
<omitted>
[2024-04-23T15:56:19.488+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-61-tccea81c
[2024-04-23T15:56:19.488+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-60-3vx8m1ak is Running, annotations:
<omitted>
[2024-04-23T15:56:19.683+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-61-tccea81c is Running, annotations:
<omitted>
[2024-04-23T15:56:19.685+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-62-wm5f7it8
[2024-04-23T15:56:19.884+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-63-tan8e9mj
[2024-04-23T15:56:19.886+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-62-wm5f7it8 is Running, annotations:
<omitted>
[2024-04-23T15:56:20.082+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-65-a8j9q7d1
[2024-04-23T15:56:20.096+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-63-tan8e9mj is Running, annotations:
<omitted>
[2024-04-23T15:56:20.199+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-70-no28k3w3
[2024-04-23T15:56:20.382+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-65-a8j9q7d1 is Running, annotations:
<omitted>
[2024-04-23T15:56:20.387+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-76-44539ook
[2024-04-23T15:56:20.485+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-70-no28k3w3 is Running, annotations:
<omitted>
[2024-04-23T15:56:20.588+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-76-44539ook is Running, annotations:
<omitted>
[2024-04-23T15:56:20.588+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-77-zq4wpeqz
[2024-04-23T15:56:20.787+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-77-zq4wpeqz is Running, annotations:
<omitted>
[2024-04-23T15:56:20.887+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-78-90a0rqll
[2024-04-23T15:56:20.999+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-79-mbefhn42
[2024-04-23T15:56:20.999+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-78-90a0rqll is Running, annotations:
<omitted>
[2024-04-23T15:56:21.101+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-79-mbefhn42 is Running, annotations:
<omitted>
[2024-04-23T15:56:21.105+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-8-zs4sulzt
[2024-04-23T15:56:21.301+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-80-ayuh71yt
[2024-04-23T15:56:21.301+0000] {kubernetes_executor_utils.py:289} INFO -
Event: test-orphaned-test-dag-select-8-zs4sulzt Succeeded, annotations:
<omitted>
[2024-04-23T15:56:21.404+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-81-9v51k09i
[2024-04-23T15:56:21.496+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-80-ayuh71yt is Running, annotations:
<omitted>
[2024-04-23T15:56:21.504+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-82-5u370a8f
[2024-04-23T15:56:21.596+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-81-9v51k09i is Running, annotations:
<omitted>
[2024-04-23T15:56:21.701+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-84-j5i87oo2
[2024-04-23T15:56:21.704+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-82-5u370a8f is Running, annotations:
<omitted>
[2024-04-23T15:56:21.799+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-86-jgn2e9uu
[2024-04-23T15:56:21.800+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-84-j5i87oo2 is Running, annotations:
<omitted>
[2024-04-23T15:56:21.900+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-86-jgn2e9uu is Running, annotations:
<omitted>
[2024-04-23T15:56:21.904+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-87-n5lbhsl6
[2024-04-23T15:56:21.999+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-87-n5lbhsl6 is Running, annotations:
<omitted>
[2024-04-23T15:56:22.002+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-88-5uvrywjh
[2024-04-23T15:56:22.194+0000] {kubernetes_executor.py:661} INFO -
attempting to adopt pod test-orphaned-test-dag-select-89-uo51ntoz
[2024-04-23T15:56:22.199+0000] {kubernetes_executor_utils.py:304} INFO -
Event: test-orphaned-test-dag-select-88-5uvrywjh is Running, annotations:
<omitted>
[2024-04-23T15:56:22.300+0000] {kubernetes_executor_utils.py:289} INFO -
Event: test-orphaned-test-dag-select-89-uo51ntoz Succeeded, annotations:
<omitted>
[2024-04-23T15:56:22.383+0000] {kubernetes_executor.py:702} INFO -
Attempting to adopt pod test-orphaned-test-dag-select-75-2kdv9lu0
[2024-04-23T15:56:22.397+0000] {kubernetes_executor_utils.py:289} INFO -
Event: test-orphaned-test-dag-select-78-90a0rqll Succeeded, annotations:
<omitted>
[2024-04-23T15:56:22.501+0000] {kubernetes_executor.py:702} INFO -
Attempting to adopt pod test-orphaned-test-dag-select-83-8vjoq1y7
[2024-04-23T15:56:22.600+0000] {kubernetes_executor_utils.py:289} INFO -
Event: test-orphaned-test-dag-select-75-2kdv9lu0 Succeeded, annotations:
<omitted>
[2024-04-23T15:56:22.697+0000] {kubernetes_executor_utils.py:289} INFO -
Event: test-orphaned-test-dag-select-83-8vjoq1y7 Succeeded, annotations:
<omitted>
[2024-04-23T15:56:23.319+0000] {scheduler_job_runner.py:1671} INFO - Reset
the following 27 orphaned TaskInstances:
<TaskInstance: test__orphaned_test_dag.select_25
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_26
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_27
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_28
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_29
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_3
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_32
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_56
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_57
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_59
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_6
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_60
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_61
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_62
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_63
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_65
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_70
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_76
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_77
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_79
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_80
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_81
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_82
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_84
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_86
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_87
scheduled__2024-04-23T14:30:00+00:00 [running]>
<TaskInstance: test__orphaned_test_dag.select_88
scheduled__2024-04-23T14:30:00+00:00 [running]>
```
error log of `test__orphaned_test_dag.select_26` Task instance worker pod:
```
[2024-04-24, 00:54:14 JST] {taskinstance.py:1979} INFO - Dependencies all
met for dep_context=non-requeueable deps ti=<TaskInstance:
test__orphaned_test_dag.select_26 scheduled__2024-04-23T14:30:00+00:00 [queued]>
[2024-04-24, 00:54:14 JST] {taskinstance.py:1979} INFO - Dependencies all
met for dep_context=requeueable deps ti=<TaskInstance:
test__orphaned_test_dag.select_26 scheduled__2024-04-23T14:30:00+00:00 [queued]>
[2024-04-24, 00:54:14 JST] {taskinstance.py:2193} INFO - Starting attempt 1
of 4
[2024-04-24, 00:54:14 JST] {taskinstance.py:2217} INFO - Executing
<Task(MyDummyOperator): select_26> on 2024-04-23 14:30:00+00:00
[2024-04-24, 00:54:14 JST] {standard_task_runner.py:60} INFO - Started
process 12 to run task
[2024-04-24, 00:54:14 JST] {standard_task_runner.py:87} INFO - Running:
['airflow', 'tasks', 'run', 'test__orphaned_test_dag', 'select_26',
'scheduled__2024-04-23T14:30:00+00:00', '--job-id', '5713', '--raw',
'--subdir', 'DAGS_FOLDER/my_dag.py', '--cfg-path', '/tmp/tmp5mif6w64']
[2024-04-24, 00:54:14 JST] {standard_task_runner.py:88} INFO - Job 5713:
Subtask select_26
[2024-04-24, 00:54:14 JST] {task_command.py:423} INFO - Running
<TaskInstance: test__orphaned_test_dag.select_26
scheduled__2024-04-23T14:30:00+00:00 [running]> on host
test-orphaned-test-dag-select-26-v3hdab2d
[2024-04-24, 00:54:14 JST] {logging_mixin.py:188} WARNING -
/usr/local/lib/python3.10/site-packages/airflow/providers/cncf/kubernetes/template_rendering.py:46
AirflowProviderDeprecationWarning: This function is deprecated. Please use
`create_unique_id`.
[2024-04-24, 00:54:14 JST] {logging_mixin.py:188} WARNING -
/usr/local/lib/python3.10/site-packages/airflow/providers/cncf/kubernetes/kubernetes_helper_functions.py:145
AirflowProviderDeprecationWarning: This function is deprecated. Please use
`add_unique_suffix`.
[2024-04-24, 00:54:14 JST] {pod_generator.py:555} WARNING - Model file
/opt/airflow/pod_templates/pod_template_file.yaml does not exist
[2024-04-24, 00:54:14 JST] {taskinstance.py:2513} INFO - Exporting env vars:
AIRFLOW_CTX_DAG_OWNER='test' AIRFLOW_CTX_DAG_ID='test__orphaned_test_dag'
AIRFLOW_CTX_TASK_ID='select_26'
AIRFLOW_CTX_EXECUTION_DATE='2024-04-23T14:30:00+00:00'
AIRFLOW_CTX_TRY_NUMBER='1'
AIRFLOW_CTX_DAG_RUN_ID='scheduled__2024-04-23T14:30:00+00:00'
[2024-04-24, 00:54:14 JST] {my_dummy_operator.py:142} INFO - Task started.
Sleeping for 5 minutes.
[2024-04-24, 00:57:14 JST] {local_task_job_runner.py:302} WARNING - State of
this instance has been externally set to scheduled. Terminating instance.
[2024-04-24, 00:57:14 JST] {process_utils.py:131} INFO - Sending 15 to group
12. PIDs of all processes in the group: [12]
[2024-04-24, 00:57:14 JST] {process_utils.py:86} INFO - Sending the signal
15 to group 12
[2024-04-24, 00:57:14 JST] {taskinstance.py:2483} ERROR - Received SIGTERM.
Terminating subprocesses.
[2024-04-24, 00:57:14 JST] {taskinstance.py:2731} ERROR - Task failed with
exception
Traceback (most recent call last):
File
"/usr/local/lib/python3.10/site-packages/airflow/models/taskinstance.py", line
444, in _execute_task
result = _execute_callable(context=context, **execute_callable_kwargs)
File
"/usr/local/lib/python3.10/site-packages/airflow/models/taskinstance.py", line
414, in _execute_callable
return execute_callable(context=context, **execute_callable_kwargs)
File "/opt/airflow/plugins/operators/my_dummy_operator.py", line 143, in
execute
time.sleep(300)
File
"/usr/local/lib/python3.10/site-packages/airflow/models/taskinstance.py", line
2485, in signal_handler
raise AirflowException("Task received SIGTERM signal")
airflow.exceptions.AirflowException: Task received SIGTERM signal
[2024-04-24, 00:57:14 JST] {taskinstance.py:1149} INFO - Marking task as
UP_FOR_RETRY. dag_id=test__orphaned_test_dag, task_id=select_26,
execution_date=20240423T143000, start_date=20240423T155414,
end_date=20240423T155714
[2024-04-24, 00:57:16 JST] {standard_task_runner.py:107} ERROR - Failed to
execute job 5713 for task select_26 (Task received SIGTERM signal; 12)
[2024-04-24, 00:57:16 JST] {process_utils.py:79} INFO - Process
psutil.Process(pid=12, status='terminated', exitcode=1, started='15:54:14')
(12) terminated with exit code 1
```
--
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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
