Skip to content

Use monotonic clock for OpenAIBatchTrigger polling timeout - #69534

Merged
potiuk merged 1 commit into
apache:mainfrom
YAshhh29:fix-openai-batch-trigger-monotonic-clock
Aug 1, 2026
Merged

Use monotonic clock for OpenAIBatchTrigger polling timeout#69534
potiuk merged 1 commit into
apache:mainfrom
YAshhh29:fix-openai-batch-trigger-monotonic-clock

Conversation

@YAshhh29

@YAshhh29 YAshhh29 commented Jul 7, 2026

Copy link
Copy Markdown
Contributor

OpenAIBatchTrigger measures its polling timeout with time.time() (wall
clock) in two places, and OpenAITriggerBatchOperator sets the deadline
with time.time() + self.timeout. Because wall-clock time can jump — NTP
corrections, DST, container clock skew, VM pause/resume — a deferred batch
task can either time out early or run far past its intended deadline.

This isn't tied to an existing issue — I spotted it while auditing
time.time()/time.monotonic() usage across the AI/ML providers, in the
same spirit as the dep-audit that produced #69408.

Airflow's own coding standards flag this exact pattern:

time.monotonic() for durations, not time.time().

.github/instructions/code-review.instructions.md and AGENTS.md

Why the fix isn't a one-line swap

time.monotonic() values are only meaningful within a single process. The
operator (in the worker) and the trigger (in the Triggerer) run in
different processes, so the operator cannot pre-compute a monotonic
deadline and hand it to the trigger. The trigger must call
time.monotonic() itself.

To make that possible the trigger's preferred constructor argument
changed from end_time (absolute wall-clock deadline) to timeout (a
duration in seconds). The trigger now records time.monotonic() at the
start of run() and reports the elapsed monotonic duration on timeout.

Backward compatibility

OpenAIBatchTrigger.__init__ still accepts the legacy end_time
argument so that triggers serialized by the previous version of the
operator continue to run after an upgrade. When a legacy end_time is
present the trigger derives a best-effort remaining duration from the
wall clock once, then tracks the rest with the monotonic clock — so even
the legacy path is no longer fully at the mercy of wall-clock jumps
inside the polling loop. serialize() preserves whichever argument the
trigger was constructed with, so a rolling upgrade never rewrites an
in-flight trigger's schema.

What changes

  • providers/openai/src/.../triggers/openai.py
    • Add timeout: float | None constructor arg and validation
      (exactly one of timeout/end_time must be given).
    • run() measures elapsed time via time.monotonic().
    • serialize() emits whichever field the trigger was constructed with.
    • Timeout error message now reports actual elapsed seconds (previously
      it reported time.time() - self.end_time, which is seconds past
      the deadline — misleading and sometimes negative).
  • providers/openai/src/.../operators/openai.py
    • Passes timeout=self.timeout instead of computing end_time.
    • Removes the now-unused import time.
  • providers/openai/tests/.../test_openai.py
    • Existing tests now use timeout=.
    • New test_serialization_with_legacy_end_time proves the
      backward-compat serialization path.
    • New test_timeout_uses_monotonic_not_wall_clock — the regression
      test — patches time.monotonic with an ever-increasing counter and
      asserts the timeout fires while time.time is never consulted. It
      fails against the pre-fix code, which decided the timeout from the
      wall clock. (time.monotonic is mocked with itertools.count
      rather than a fixed list because the asyncio event loop also calls
      time.monotonic internally and would exhaust a finite side_effect.)
    • Constructor validation tests for the "neither" and "both" error paths.
  • providers/openai/docs/changelog.rst: bug-fix note explaining the
    behavior change and the end_timetimeout migration.

How to reproduce the original bug

  1. Deploy a DAG with OpenAITriggerBatchOperator(deferrable=True, timeout=600).
  2. While the batch is running and the trigger is deferred, force a
    backward wall-clock adjustment on the Triggerer host (e.g.
    sudo date -s '10 minutes ago', or a large NTP step).
  3. Observe that the trigger keeps polling well past 600 seconds because
    self.end_time < time.time() is no longer true.

The same pattern also fires early on forward clock jumps.

Related


Was generative AI tooling used to co-author this PR?
  • Yes — GitHub Copilot (Claude Opus 4.6)

Generated-by: GitHub Copilot (Claude Opus 4.6) following the guidelines

@YAshhh29

YAshhh29 commented Jul 8, 2026

Copy link
Copy Markdown
Contributor Author

Fixed the CI failures:

  1. The trigger tests mocked time.monotonic with a fixed 2-element list, but the asyncio event loop calls time.monotonic internally — it exhausted the mock and raised StopIteration (which is why only the non-DB / lowest-deps / compat jobs failed; the trigger tests are deselected in the DB backends). Switched to an ever-increasing itertools.count side_effect that the loop can call freely; the trigger's two clock reads are consecutive so measured elapsed is deterministic.
  2. Fixed British serialised → American serialized spellings that failed the docs spellcheck.

Verified the trigger under a real event loop locally.


Drafted-by: GitHub Copilot (Claude Opus 4.6); reviewed by @YAshhh29 before posting

@YAshhh29
YAshhh29 force-pushed the fix-openai-batch-trigger-monotonic-clock branch from 94aeeb2 to 82da305 Compare July 8, 2026 17:27
@YAshhh29
YAshhh29 force-pushed the fix-openai-batch-trigger-monotonic-clock branch from 82da305 to 7049699 Compare July 20, 2026 05:34
@potiuk potiuk added the ready for maintainer review Set after triaging when all criteria pass. label Jul 20, 2026
@YAshhh29
YAshhh29 force-pushed the fix-openai-batch-trigger-monotonic-clock branch from 7049699 to c1ac129 Compare July 23, 2026 15:26

@potiuk potiuk left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch, and it fixes a real violation of our own standard — a deferred trigger is exactly the long-lived thing most exposed to wall-clock jumps, so measuring its deadline against time.time() could either cut a batch short or let it run far past the intended timeout.

The rolling-upgrade handling is the part I most appreciate. Keeping end_time accepted and serializing whichever argument the trigger was constructed with means a trigger serialized by the previous operator and still deferred through an upgrade keeps deserializing correctly, instead of failing on an unexpected keyword. Converting the legacy deadline into a remaining duration exactly once and tracking the rest monotonically is the right shape, and it is the detail most changes like this skip.

It also quietly fixes a misleading message: the old text interpolated time.time() - self.end_time, which is the overshoot past the deadline rather than elapsed time, while claiming "has not reached a terminal status after N seconds". A batch running an hour past a sixty second deadline reported a number unrelated to either.

test_timeout_uses_monotonic_not_wall_clock is the test that earns its place — patching both clocks proves the wall clock is genuinely ignored, rather than just that some timeout eventually fires.

One small thing, not worth holding this for: end_time is documented as deprecated but raises no AirflowProviderDeprecationWarning. I suspect that is deliberate, since warning on every deserialization of an in-flight trigger would be noise during exactly the upgrade window the compatibility exists for — but a direct user of the trigger gets no signal that they should move.


Drafted-by: Claude Code (Opus 5); reviewed by @potiuk before posting

@potiuk
potiuk merged commit b2d1d81 into apache:main Aug 1, 2026
79 checks passed
jason810496 pushed a commit that referenced this pull request Aug 2, 2026
Two PRs merged three hours apart on 2026-08-01 collided semantically:
#69506 added a test using the class attribute END_TIME, and #69534
renamed that attribute to LEGACY_END_TIME while branched off a main
that predated #69506. Git merged both cleanly, so the dangling
reference reached main unnoticed and every job that collects the
OpenAI provider tests now fails.

The case asserts that a terminal batch emits exactly one event, which
has nothing to do with the deprecated wall-clock deadline, so it moves
to the timeout constant that the rest of the behavioural cases use
rather than to LEGACY_END_TIME. The end_time path stays covered by
test_serialization_with_legacy_end_time.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants