/ AIRFLOW, KUBERNETES

KubernetesPodOperator에서 ApiException(400)가 발생하는 원인

  • KubernetesPodOperator 사용 시 kubernetes.client.exceptions.ApiException: (400)이 발생하는 원인에 대해서 분석합니다.

문제 상황: kubernetes.client.exceptions.ApiException: (400) 발생

  File "/usr/local/lib/python3.12/site-packages/kubernetes/client/rest.py", line 234, in request
    raise ApiException(http_resp=r)
kubernetes.client.exceptions.ApiException: (400)
Reason: Bad Request
...
[2025-10-01, 07:21:10 KST] {pod_manager.py:365} WARNING - Pod not yet started: { pod_name }
[2025-10-01, 07:21:11 KST] {pod_manager.py:365} WARNING - Pod not yet started: { pod_name }
[2025-10-01, 07:21:42 KST] {pod.py:844} INFO - Deleting pod: { pod_name }
  • cncf-kubernetes==7.13.0 사용 시 위와 같은 로그를 남기며 KubernetesPodOpeartor가 실패하는 경우가 종종 발생합니다.
  • 항상 발생하는 것은 아니며, 간헐적으로 발생했습니다. 특히, 대부분의 경우에 task를 재실행하면 Pod이 정상적으로 생성/실행되어서 해당 현상을 재현하기 어려웠고 원인을 파악하기 힘들었습니다.
  • task의 실패를 최소화하기 위해 원인을 파악하고 대응해보고자 합니다.

kubernetes.client.exceptions.ApiException: (400) 에러의 의미

  • 생성된 Pod로부터 log를 읽을 수 없을 때 발생합니다.
  • 실제로 아직 Running phase가 아닌 Pod(Pending pod)에 대해서 kubectl logs <pod-name>를 실행하면 동일한 에러를 확인할 수 있습니다.
  • 다만, airflow에 남은 로그를 확인해보았을 때, Pod는 이미 Running 상태인 것으로 보입니다. Pod not yet started 로그는 Pod Phase가 Pending일 때의 로그인 것으로 확인했고, 해당 로그가 등장하지 않으면 Running 상태인 것으로 확인했기 때문입니다.

KubernetesPodOperator는 언제 log를 가져오나?

  • KubernetesPodOperator의 동작 방식은 대략적으로 아래와 같습니다.
    • get_or_create_pod : pod를 생성합니다
    • await_pod_start: pod start를 대기합니다. 즉, pod가 Running phase가 될 때까지 대기합니다.
    • fetch_requested_container_logs: Running Pod 내에 base container로부터 log를 가져옵니다.
    • clean_up/deleting_pod: 위 과정 중에 에러가 발생하는 경우에 Pod를 삭제합니다.
  • 위 과정 중 fetch_requested_container_logs에서 문제가 발생하는 것으로 보입니다.
  • 여기까지 보면 Running Pod 내부의 base container의 로그를 가져오지 못했기 때문에 에러가 발생하는 것으로 볼 수 있습니다.

Running Pod에 대해서도 ApiException(400)이 발생할 수 있다

  • 위에서 Pending Pod에 대해 kubectl logs 명령어 실행 시 ApiException(400)이 발생한다고 말씀드렸습니다.
  • Running Pod에 대해서도 동일한 에러가 발생할 수 있습니다. 이는 Running Pod인 경우에 Pod 내의 모든 container가 실행 중인 상태는 아니기 때문입니다.
  • Pod 내에 a, b, c container를 실행한다고 가정할 때 a, b는 아직 실행되지 않아 wataing state이고, c만 실행되어 running state라면 이 Pod는 Running phase입니다.
  • 이 때 a나 b의 log를 조회하려고 하면 ApiException(400)이 발생합니다(kubectl logs <pod-name> --container a).

[참고]Pod Phase에 대하여

  • Pod는 5개의 Phase를 갖습니다.(Pending, Running, Succeeded, Failed, Unknown)
    • 이 중에서 Pending, Running이 현재 발생하는 에러와 연관이 있습니다.
  • Pending Phase는 아직 Pod이 실행되지 않았고, 실행(Running)을 준비하는 단계입니다. k8s 클러스터로부터 Pod 생성이 허용되고, container image를 다운로드 받습니다.
  • Running Phase는 실제로 Pod이 실행되는 단계입니다. Pod 내에 1개 이상의 container가 실행되고 있는 단계입니다.
    • 즉, Running이라고 해서 모든 container가 running 상태는 아니라는 뜻입니다.
    • pod 내에 sidecar 형태로 3개의 container를 선언했고, 이 중 1개의 container라도 running에 돌입했다면 pod phase는 running이 됩니다.

에러의 원인: XComPush를 위해 추가된 airflow-xcom-sidecar

  • KubernetesPodOperator는 base container를 생성하여 입력된 cmd, args를 실행합니다.
  • Pod Phase가 Running으로 돌입하면, 생성된 Pod 내에 base container의 로그를 가져오는 코드를 실행합니다(fetch_requested_container_logs).
  • 보통 KubernetesPodOperator를 사용하여 생성된 Pod은 base container 1개만 실행합니다(init container가 완료된 후 실행되는 container는 1개).
  • 그러나 XCom Push를 사용하기 위해 do_xcom_push=True 옵션을 주면 base container 외에 xcom push을 위한 컨테이너(airflow-xcom-sidecar)를 생성합니다(=Side Car 패턴)
  • 해당 컨테이너는 base container의 작업이 완료되어도 volume이 삭제되지 않도록 유지하는 역할을 합니다. base container의 작업이 종료되어도 XComPush path(/airflow/xcom/return.json)에 대한 volume mount를 유지하여 airflow worker에서 해당 값을 참조할 수 있도록 하는 역할을 합니다.
  • 해당 컨테이너는 가벼운 docker image(alpine)를 사용하기 때문에 base container에 비해 더 빠르게 시작됩니다.
  • 위의 Pod Phase를 다시 보면, Pod의 Running Phase는 Pod 내의 N개의 container 중 1개의 container라도 running인 경우입니다.
  • 따라서 airflow-xcom-sidecar는 running, base는 waiting인 상태에서도 Pod Phase는 Running으로 돌입합니다.
  • Running Phase Pod에 대해서airflow는 fetch_requested_container_logs 함수를 실행합니다.
  • 하지만 base container가 아직 실행되지 않은 상태이기 때문에 존재하지 않는 container로의 요청이므로 400 error(Bad Request)가 발생합니다.

providers-cncf-kubernetes==10.8.2에서의 변화

  • 최신 버전에서 이 부분에 대해 수정이 되었는지 확인해보았습니다.
  • 먼저 7.13.0에서의 await_pos_start 코드는 아래와 같습니다.
## cncf/kubernetes/utils/pod_manager.py (apache-airflow-providers-cncf-kubernetes==7.13.0)
    def await_pod_start(
        self, pod: V1Pod, startup_timeout: int = 120, startup_check_interval: int = 1
    ) -> None:
        """
        Wait for the pod to reach phase other than ``Pending``.

        :param pod:
        :param startup_timeout: Timeout (in seconds) for startup of the pod
            (if pod is pending for too long, fails task)
        :param startup_check_interval: Interval (in seconds) between checks
        :return:
        """
        curr_time = time.time()
        while True:
            remote_pod = self.read_pod(pod)
            if remote_pod.status.phase != PodPhase.PENDING: ## <- PodPhase를 기준으로 판단하고 있음
                break
            self.log.warning("Pod not yet started: %s", pod.metadata.name)
            if time.time() - curr_time >= startup_timeout:
                msg = (
                    f"Pod took longer than {startup_timeout} seconds to start. "
                    "Check the pod events in kubernetes to determine why."
                )
                raise PodLaunchFailedException(msg)
            time.sleep(startup_check_interval)
  • 최신 버전(providers-cncf-kubernetes==10.8.2)에서는 아래와 같이 container state를 확인하는 코드가 추가되었습니다.
        if pod_status.container_statuses:
            for container_status in pod_status.container_statuses:
                container_state: V1ContainerState = container_status.state
                container_waiting: V1ContainerStateWaiting | None = container_state.waiting
                if container_waiting:
                    if container_waiting.reason in ["ErrImagePull", "InvalidImageName"]:
                        self.log.info("::endgroup::")
                        raise PodLaunchFailedException(
                            f"Pod docker image cannot be pulled, unable to start: {container_waiting.reason}"
                            f"\n{container_waiting.message}"
                        )
  • Pod 내에 waiting state인 container에 대해서 Image 관련 에러가 발생하는 경우 조기에 실패시키는 코드입니다.
  • 그러나 여전히 Pod Phase에 의존하는 방식은 변경되지 않았습니다.
  • 어떤 이유에서든지 base container가 wating이고 sidecar container가 running이라면 여전히 동일한 에러가 발생할 것으로 보입니다.
  • image 관련 에러가 발생하는 경우에는 추가된 코드를 통해 조기에 Pod을 종료시키지만, 클러스터 내 자원(CPU, memory)을 할당받지 못해 base container가 늦게 시작되는 경우에 대해서는 감지하지 않는 것으로 보입니다.
  • 즉, 여전히 ApiException(400)은 발생할 가능성이 있어 보입니다.

base container가 waiting인 경우에 대해서의 감지를 추가하기

  • Kubernetes는 init container를 제외하면 container들 간의 실행 순서(시작 순서)를 제어할 수 있는 방법은 제공하지 않습니다.
  • 혹은 특정 container가 running일 때 Pod가 Running Phase에 돌입한다던가 하는 방법도 존재하지 않습니다.
  • 따라서 fetch_requested_container_logs가 실행되기 전에 await_pod_start를 수정하는 것이 적합한 방향입니다.

결론

  • do_xcom_push=True 사용 시 Pod Phase와 base container state의 불일치로 인해 해당 에러가 발생할 수 있습니다.

[참고]
Pod Phase