RayVilaca opened a new issue, #71202:
URL: https://github.com/apache/airflow/issues/71202

   ### Under which category would you file this issue?
   
   Providers
   
   ### Apache Airflow version
   
   3.3.0
   
   ### What happened and how to reproduce it?
   
   **Architecture context**
   
   This happens when using `KubernetesExecutor` together with 
`KubernetesPodOperator`, which involves two separate pods:
   
   1. **The per-task pod** created by `KubernetesExecutor` to execute the task 
instance.
   2. **The child pod** created by `KubernetesPodOperator.execute()` to run the 
user's workload.
   
   **Issue Description**
   
   When both pods are interrupted within roughly one second of each other, the 
task instance is sometimes finalized as `success`, even though the child pod 
never completed its work.
   
   **Steps to reproduce**
   
   1. Trigger a DAG task using `KubernetesPodOperator` whose child pod runs 
long enough to still be running when interrupted. Example:
   ```
   from datetime import datetime
   from airflow import DAG
   from airflow.models import Variable
   from airflow.providers.cncf.kubernetes.operators.pod import 
KubernetesPodOperator
   
   default_args = {
       "owner": "data",
       "depends_on_past": False,
       "start_date": datetime.strptime("2026-08-05", "%Y-%m-%d"),
       "params": {
           "severity": 0,
       },
       "retries": 1,
   }
   
   dag = DAG(
       dag_id="air-test-sigterm-repro",
       default_args=default_args,
       catchup=False,
       schedule=None,
       max_active_runs=1
   )
   
   sleep_worker = KubernetesPodOperator(
       dag=dag,
       task_id="sleep-worker",
       name="sleep-worker",
       namespace=Variable.get("var-k8s-namespace"),
       image="python:3.9",
       cmds=["python", "-c"],
       do_xcom_push=False,
       get_logs=True,
       is_delete_operator_pod=True,
       arguments=[
           "import time\n"
           "for i in range(120):\n"
           "    print('tick', i, 'still running, still streaming logs', 
flush=True)\n"
           "    time.sleep(5)\n"
           "print('finished without interruption', flush=True)\n"
       ],
   )
   
   ``` 
   2. While the task is running, delete **both** the child pod and the per-task 
pod within the same short time window (rather than waiting for one deletion to 
complete). The most reliable sequence we found is to delete the child pod 
first, then the per-task pod about one second later.
   
      Terminal 1 — **child pod**:
      ```bash
      kubectl delete pod sleep-worker-xxxxxxx -n airflow --grace-period=30
      ```
   
      Terminal 2 (~1 second later) — **per-task pod**:
      ```bash
      kubectl delete pod air-test-sigterm-repro-sleep-worker-xxxxxxxxx -n 
airflow --grace-period=30
      ```
   
   3. Observe the task's final state in the Airflow UI or API.
   
   <img width="1830" height="784" alt="Image" 
src="https://github.com/user-attachments/assets/16af92ab-491f-4fc1-8c37-9e3d9467c6f3";
 />
   
   logs sleep-worker-xxxxxxx
   ```text
   tick 0 still running, still streaming logs
   tick 1 still running, still streaming logs
   tick 2 still running, still streaming logs
   tick 3 still running, still streaming logs
   tick 4 still running, still streaming logs
   tick 5 still running, still streaming logs
   tick 6 still running, still streaming logs
   tick 7 still running, still streaming logs
   tick 8 still running, still streaming logs
   tick 9 still running, still streaming logs
   tick 10 still running, still streaming logs
   tick 11 still running, still streaming logs
   tick 12 still running, still streaming logs
   tick 13 still running, still streaming logs
   tick 14 still running, still streaming logs
   tick 15 still running, still streaming logs
   tick 16 still running, still streaming logs
   tick 17 still running, still streaming logs
   ```
   logs air-test-sigterm-repro-sleep-worker-xxxxxxxxx
   ```text
   
{"timestamp":"2026-08-05T18:49:28.622020Z","level":"info","event":"::endgroup::","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":186}
   {"timestamp":"2026-08-05T18:49:29.219279Z","level":"info","event":"[base] 
tick 0 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:34.224101Z","level":"info","event":"[base] 
tick 1 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:39.229335Z","level":"info","event":"[base] 
tick 2 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:44.230741Z","level":"info","event":"[base] 
tick 3 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:49.235802Z","level":"info","event":"[base] 
tick 4 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:54.240729Z","level":"info","event":"[base] 
tick 5 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:49:59.245828Z","level":"info","event":"[base] 
tick 6 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:04.247038Z","level":"info","event":"[base] 
tick 7 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:09.247528Z","level":"info","event":"[base] 
tick 8 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:14.250719Z","level":"info","event":"[base] 
tick 9 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:19.255868Z","level":"info","event":"[base] 
tick 10 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:24.256810Z","level":"info","event":"[base] 
tick 11 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:29.261832Z","level":"info","event":"[base] 
tick 12 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:34.266976Z","level":"info","event":"[base] 
tick 13 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:39.272003Z","level":"info","event":"[base] 
tick 14 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:44.277099Z","level":"info","event":"[base] 
tick 15 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:49.282109Z","level":"info","event":"[base] 
tick 16 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:54.286787Z","level":"info","event":"[base] 
tick 17 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:50:59.288915Z","level":"info","event":"[base] 
tick 18 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:04.293390Z","level":"info","event":"[base] 
tick 19 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:09.296800Z","level":"info","event":"[base] 
tick 20 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:14.301846Z","level":"info","event":"[base] 
tick 21 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:19.306809Z","level":"info","event":"[base] 
tick 22 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:24.311349Z","level":"info","event":"[base] 
tick 23 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:29.315332Z","level":"info","event":"[base] 
tick 24 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:34.316805Z","level":"info","event":"[base] 
tick 25 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:36.975521Z","level":"info","event":"Received 
signal, forwarding to task 
subprocess","signal":"SIGTERM","pid":13,"logger":"supervisor","filename":"supervisor.py","lineno":1403}
   {"timestamp":"2026-08-05T18:51:39.344660Z","level":"info","event":"[base] 
tick 26 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   {"timestamp":"2026-08-05T18:51:44.322040Z","level":"info","event":"[base] 
tick 27 still running, still streaming 
logs","task_id":"sleep-worker","map_index":-1,"try_number":1,"run_id":"manual__2026-08-05T18:49:11.709471+00:00","dag_id":"air-test-sigterm-repro","ti_id":"019fd342-172e-7f4b-8c58-eebe3cb6bc91","logger":"airflow.providers.cncf.kubernetes.utils.pod_manager.PodManager","filename":"pod_manager.py","lineno":500}
   ```
   
   Deleting only one of the two pods did **not** reproduce the issue in our 
testing. In those cases, the task correctly transitioned to `failed` or 
`up_for_retry`.
   
   **What we observe when it reproduces**
   
   The last log emitted by the per-task pod is:
   
   ```text
   {"event":"Received signal, forwarding to task 
subprocess","signal":"SIGTERM","pid":13,"logger":"supervisor","filename":"supervisor.py","lineno":1403}
   ```
   
   After that, we never see:
   
   - `on_kill()` being invoked.
   - The provider's `"Deleting pod: ..."` log line.
   - Any exception or traceback.
   - Any further output from the child pod.
   
   Despite the child pod being interrupted before completing its work, the task 
is later reported by the API server as `success`.
   
   **Observed in production**
   
   We observed this four times across two different DAGs over four days. Every 
occurrence coincided with our autoscaler reclaiming a Spot/preemptible node 
hosting one or both pods.
   
   When the issue reproduces:
   
   ```text
   19:12:28Z  [child pod progress log — task actively running]
   19:12:42Z  <node hosting the per-task pod begins draining>
   19:12:44Z  {"event":"Received signal, forwarding to task 
subprocess","signal":"SIGTERM","pid":13,"logger":"supervisor"}
              <nothing else logged>
              --> Task instance later shows state = success
   ```
   
   A normal execution of the same task instead includes:
   
   ```text
   {"event":"Deleting pod: <pod-name>", ...}
   {"event":"::group::Post Execute", ...}
   {"event":"Workload finished", "final_state":"success", ...}
   ```
   
   **Contrast: interrupting only the child pod**
   
   If only the child pod is interrupted while the per-task pod continues 
running, the task correctly fails. We've observed both `AirflowException` 
(PodFailed) and `NotFoundException` (404 after pod deletion), but in both cases 
the task is never reported as `success`.
   
   ### What you think should happen instead?
   
   The task should end in `failed` (or `up_for_retry`), just as it does when 
only the child pod is interrupted. Reporting `success` for a task whose 
workload never completed is a correctness issue, downstream tasks proceed as if 
the work succeeded, `on_failure_callback` is never triggered, and no retry 
occurs.
   
   We haven't identified the root cause and are only reporting the observed, 
reproducible behavior. This may be related to #58936 (fixed by #61627 in 
3.3.0), which changed how `SIGTERM` is forwarded from the supervisor to the 
task subprocess. The last log we consistently see (`"Received signal, 
forwarding to task subprocess"`) originates from that change, although we can't 
confirm whether this is a regression from that fix or a separate issue.
   
   
   ### Operating System
   
   Debian GNU/Linux 12 (bookworm)
   
   ### Deployment
   
   Official Apache Airflow Helm Chart
   
   ### Apache Airflow Provider(s)
   
   cncf-kubernetes
   
   ### Versions of Apache Airflow Providers
   
   apache-airflow-providers-cncf-kubernetes==10.19.0
   
   ### Official Helm Chart version
   
   1.18.0
   
   ### Kubernetes Version
   
   _No response_
   
   ### Helm Chart configuration
   
   _No response_
   
   ### Docker Image customizations
   
   _No response_
   
   ### Anything else?
   
   _No response_
   
   ### Are you willing to submit PR?
   
   - [ ] Yes I am willing to submit a PR!
   
   ### Code of Conduct
   
   - [x] I agree to follow this project's [Code of 
Conduct](https://github.com/apache/airflow/blob/main/CODE_OF_CONDUCT.md)
   


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

Reply via email to