Skip to content

fix(cli/train): bound the training log fetch with a deadline - #2594

Open
spal1 wants to merge 1 commit into
mainfrom
samiksha/bound-training-log-fetch
Open

fix(cli/train): bound the training log fetch with a deadline#2594
spal1 wants to merge 1 commit into
mainfrom
samiksha/bound-training-log-fetch

Conversation

@spal1

@spal1 spal1 commented Aug 4, 2026

Copy link
Copy Markdown
Collaborator

What

truss train logs (without --tail) could run essentially forever. It now stops at a deadline and returns the logs it has.

Why

The non-tail path paginates forward from the job's first log, one request per MAX_BATCH_SIZE (1000) lines, with no wall-clock bound (get_training_job_logs_with_pagination). A chatty job needs many sequential requests, so the command outruns whatever timeout the caller imposed, and the caller reports its own timeout instead of the job's logs.

This is not hypothetical. basetenlabs/ml-cookbook's training smoke tests have been red every scheduled run since 2026-06-23, and the only error visible in any of those runs is:

FAIL: Command '['uv', 'run', 'truss', 'train', 'logs', '--job-id', 'w5ov4mq', ...]' timed out after 300 seconds
subprocess.TimeoutExpired

The actual failure (an HF weights download returning 403, so train.py died with OSError: Can't load the model for 'Qwen/Qwen3-0.6B') never made it to CI output. Six weeks of failures all looked identical and none of them named the cause. I had to pull the logs out of Loki by hand to find it.

How

  • Add timeout_sec (default 60s) to BatchedTrainingLogsFetcher and get_training_job_logs_with_pagination. On expiry the iterator stops, the caller gets the logs collected so far, and a yellow warning says the view is partial.
  • Drop a dead termination branch: if len(batch_logs) == 0 duplicated the if not batch_logs check immediately above it, so the "fewer logs than the batch size means we've reached the end" intent stated in its comment never actually ran. Terminating on a short batch would be wrong regardless, since the query window is capped at 2h and a longer-running job still has logs past it, so I corrected the comment to describe what the code does rather than making the code match the old comment.

Testing

  • uv run pytest truss/tests/remote/ -q — 207 passed.
  • New test test_get_training_job_logs_with_pagination_stops_at_timeout drives a fetcher whose batches never run out and asserts the deadline ends the scan with the first batch's logs intact.

Follow-ups (not in this PR)

Two things I noticed and deliberately left alone:

  • test_get_training_job_logs_with_pagination_max_iterations asserts that a repeated, non-advancing batch produces MAX_ITERATIONS * batch_size logs from 10,000 identical API calls. That encodes a pathological case as expected behavior. A guard that stops when the window fails to advance would be the real fix, but it changes that test's contract, so it belongs in its own PR.
  • Some existing tests in this area use millisecond timestamps in their fixtures while _process_batch_logs divides by NANOSECONDS_PER_MILLISECOND, i.e. they exercise a window arithmetic that production never produces.

Separately, for triaging a failed job the forward direction: "asc" scan is backwards: you read startup noise first and the error you want is last. A --last N mode using direction: "desc" in a single request would make failure triage instant. Happy to file that if it sounds useful.

`truss train logs` (without --tail) paginates forward from the job's first log
with one request per batch of MAX_BATCH_SIZE lines, and had no wall-clock bound.
A chatty job outruns any caller timeout, so automation that shells out to the
CLI reports its own timeout instead of the job's logs.

Concretely: basetenlabs/ml-cookbook's training smoke tests have been red since
2026-06-23, and every run's only visible error is
`subprocess.TimeoutExpired: ... 'truss', 'train', 'logs' ... timed out after 300
seconds` — the actual training failure (an HF download 403) was never printed.

Add a deadline (60s default, overridable) to BatchedTrainingLogsFetcher. On
expiry it stops, returns the logs collected so far, and prints a warning that
the view is partial. Also drop a dead termination branch: the
`len(batch_logs) == 0` check duplicated the `not batch_logs` check above it, so
the "fewer logs than batch size means done" intent in its comment never ran.
Terminating on a short batch would be wrong anyway, since the query window is
capped at 2h and a longer job still has logs past it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant