Bug: Hourly GTFS unzip/validate failing since 11/24

[lauriemerrell]

Describe the bug
Please enter a clear and concise description of the bug.

GTFS unzip/validate Airflow job has been failing in production since early last week ~11/24

To Reproduce
Please enter step by step instructions to reproduce the behavior. For example: Query column A for organization Y on date Z.

Look at production logs

Expected behavior
Please enter a clear and concise description of what you expected to happen.

Should succeed every day

Additional context
Please enter any other context about the problem here.

Probably related to #3763

[ohrite]

https://docs.cloud.google.com/composer/docs/composer-3/use-kubernetes-pod-operator

    # Timeout to start up the Pod, default is 600.
    startup_timeout_seconds=600,

[vevetron]

Since it's just the validate step, of which we barely use the data, i'm not concerned with it. I say we just worry about getting the new parser and unzipper working better.

[lauriemerrell]

@ohrite I am not sure if that setting is the one, per: https://docs.cloud.google.com/composer/docs/composer-3/use-kubernetes-pod-operator#pod_timeouts it seems like that would give a different error about pod taking too long to start as opposed to timing out while running? But I will give it a try

[lauriemerrell]

Also seems like we set that to 5 minutes rather than 10: https://github.com/cal-itp/data-infra/blob/main/airflow/plugins/operators/pod_operator.py#L14

[lauriemerrell]

Screenshots from events on pod when running locally

Resource logs

Audit logs

[lauriemerrell]

It doesn't seem like there is an issue within the pod itself, it was chugging along happily (though maybe using a bit more CPU than expected?), it's just being deleted from outside

[lauriemerrell]

startup_timeout_seconds does not seem to be making a difference, tried setting in the PodOperator and directly in the validate DAG task YAML

[lauriemerrell]

Changed is_delete_operator_pod to false and get this:

[2025-12-02, 01:22:59 UTC] {pod_manager.py:454} INFO - [base] downloading gs://calitp-staging-gtfs-schedule-raw-v2/schedule/dt=2025-11-18/ts=2025-11-18T03:00:27.701347+00:00/base64_url=aHR0cHM6Ly9hcGkuNTExLm9yZy90cmFuc2l0L2RhdGFmZWVkcz9vcGVyYXRvcl9pZD1TTQ==/GTFSTransitData_SM.zip to /tmp/tmpv0w_doun/GTFSTransitData_SM.zip
[2025-12-02, 01:23:20 UTC] {pod_manager.py:470} INFO - [base] executing schedule validator: java -jar /gtfs-validator-5.0.0-cli.jar --input /tmp/tmpv0w_doun/GTFSTransitData_SM.zip --output_base /tmp/tmpv0w_doun --country_code us-na
[2025-12-02, 01:23:20 UTC] {pod_manager.py:603} INFO - Pod validate-gtfs-schedule-o454nvtg has phase Running
[2025-12-02, 01:23:22 UTC] {pod_manager.py:603} INFO - Pod validate-gtfs-schedule-o454nvtg has phase Running
[2025-12-02, 01:23:25 UTC] {pod.py:969} INFO - Skipping deleting pod: validate-gtfs-schedule-o454nvtg
[2025-12-02, 01:23:25 UTC] {taskinstance.py:441} ▼ Post task execution logs

But it seems like this pod has still already been deleted in staging environment? Perhaps because a new one was launched validate-gtfs-schedule-bq2j5fus which has the same final logs -- phase Running and then skipping deleting.

The bq2j5fus pod shows this for memory use, maybe this is part of it....?

Pod shows as "failed" but doesn't log anything in logs besides the running validation jobs

[lauriemerrell]

Confirmed today that we are all green for 11/24 to present! 🎉
We expect only v5.0.0 validator notices. Reopened #3763 pending #4548.

[lauriemerrell]

Defer to @vevetron on what if any additional verification is needed.