feat(webapp): time "Processing…" from the hand-off, not the last edit (#534) #640

Merged
claude-bot merged 1 commit from feat/534-audio-processing-started-at into main 2026-09-14 03:26:03 +00:00
Collaborator

The session page's "Processing…" timer (#381) counted from sessions.updated_at, because the pipeline recorded no start time. Any unrelated edit (a GM renaming the session mid-transcription) reset the clock to zero.

Change

One nullable column, sessions.audio_processing_started_at, stamped wherever the status becomes processing:

  • the bot audio hand-off (routers/bot.py)
  • the GM retry (routers/sessions.py)
  • the admin retry (routers/admin.py)

It's exposed on the session response. SessionDetail anchors the timer on it, falling back to updated_at only when the column is null.

Where the stamp goes, and why not in process_audio

The #534 bullet says "set when process_audio takes the job". I didn't do that, deliberately. process_audio re-runs on every Celery retry (transport errors, and rate-limit re-queues via retry_after), and the status stays processing the whole time. A pickup stamp would restart the clock on each retry, which recreates the under-reporting this change is meant to remove. The GM sees one continuous "Processing…" from hand-off to result, and that's what the timer now measures. Provider queue time is included and is already explained by ProcessingQueueNote.

Migration c2d3e4f5a6b7

Raw DDL, TIMESTAMPTZ NULL. It backfills = updated_at for sessions currently processing, so an in-flight timer doesn't blank or jump on upgrade. It's never cleared: it's the start of the latest run and is only read while processing.

Verified locally on a scratch database: upgrade head → downgrade -1 → upgrade head. The backfill's 'processing' literal is checked against the enum even on an empty table, so a bad label would have errored.

Deliberately not changed

The stuck-task watchdog (unstick_lost_tasks) still uses updated_at < now - 8h. Moving it to this column is tempting, but its 8h cutoff would then include queue and retry-backoff time, and a busy provider could get a legitimately retrying run failed. That wants its own decision, not a ride-along.

Tests

  • test_bot_upload_audio: hand-off sets a fresh stamp.
  • test_retry_failed_audio, test_admin_retry_audio: a day-old stamp is replaced on retry.
  • SessionDetail.test.jsx: "times processing from the hand-off, not the last edit". Stamp 25m ago, updated_at 1m ago, expects Elapsed 25m 00s.
  • Migration head pin moved to this revision. The #580 pin becomes "on the one chain", following the house convention.

Mutation-checked: with the three router lines reverted, all three backend tests fail. With SessionDetail.jsx reverted, the frontend test fails.

Backend suite before the head-pin update: 3471 passed, 1 failed, 13 skipped. The one failure was the stale head pin, now fixed; the affected files were rerun green. Frontend SessionDetail + ElapsedTimer: 94 passed. ruff format --check / ruff check clean under CI's pinned 0.4.4.

No bot API change: /api/bot/sessions/{id}/audio's request and response are unchanged, so no contract bump.

Refs #534 (one of five items; the issue stays open)

🤖 Generated with Claude Code

The session page's "Processing…" timer (#381) counted from `sessions.updated_at`, because the pipeline recorded no start time. Any unrelated edit (a GM renaming the session mid-transcription) reset the clock to zero. ## Change One nullable column, `sessions.audio_processing_started_at`, stamped **wherever the status becomes `processing`**: - the bot audio hand-off (`routers/bot.py`) - the GM retry (`routers/sessions.py`) - the admin retry (`routers/admin.py`) It's exposed on the session response. `SessionDetail` anchors the timer on it, falling back to `updated_at` only when the column is null. ## Where the stamp goes, and why not in `process_audio` The #534 bullet says "set when `process_audio` takes the job". I didn't do that, deliberately. `process_audio` re-runs on every Celery retry (transport errors, and rate-limit re-queues via `retry_after`), and the status stays `processing` the whole time. A pickup stamp would restart the clock on each retry, which recreates the under-reporting this change is meant to remove. The GM sees one continuous "Processing…" from hand-off to result, and that's what the timer now measures. Provider queue time is included and is already explained by `ProcessingQueueNote`. ## Migration `c2d3e4f5a6b7` Raw DDL, `TIMESTAMPTZ NULL`. It backfills `= updated_at` for sessions currently `processing`, so an in-flight timer doesn't blank or jump on upgrade. It's never cleared: it's the start of the latest run and is only read while `processing`. Verified locally on a scratch database: `upgrade head` → `downgrade -1` → `upgrade head`. The backfill's `'processing'` literal is checked against the enum even on an empty table, so a bad label would have errored. ## Deliberately not changed The stuck-task watchdog (`unstick_lost_tasks`) still uses `updated_at < now - 8h`. Moving it to this column is tempting, but its 8h cutoff would then include queue and retry-backoff time, and a busy provider could get a legitimately retrying run failed. That wants its own decision, not a ride-along. ## Tests - `test_bot_upload_audio`: hand-off sets a fresh stamp. - `test_retry_failed_audio`, `test_admin_retry_audio`: a day-old stamp is replaced on retry. - `SessionDetail.test.jsx`: "times processing from the hand-off, not the last edit". Stamp 25m ago, `updated_at` 1m ago, expects `Elapsed 25m 00s`. - Migration head pin moved to this revision. The #580 pin becomes "on the one chain", following the house convention. **Mutation-checked:** with the three router lines reverted, all three backend tests fail. With `SessionDetail.jsx` reverted, the frontend test fails. Backend suite before the head-pin update: `3471 passed, 1 failed, 13 skipped`. The one failure was the stale head pin, now fixed; the affected files were rerun green. Frontend `SessionDetail` + `ElapsedTimer`: 94 passed. `ruff format --check` / `ruff check` clean under CI's pinned 0.4.4. No bot API change: `/api/bot/sessions/{id}/audio`'s request and response are unchanged, so no contract bump. Refs #534 (one of five items; the issue stays open) 🤖 Generated with [Claude Code](https://claude.com/claude-code)
feat(webapp): time "Processing…" from the hand-off, not the last edit (#534)
All checks were successful
CI / Backend lint (ruff) (pull_request) Successful in 46s
CI / Bot/backend version sync (pull_request) Successful in 46s
CI / Docker image build (pull_request) Successful in 47s
CI / Summarisation accuracy eval harness (stub provider) (pull_request) Successful in 1m3s
CI / Bot tests and audit (pull_request) Successful in 1m57s
CI / Frontend tests, audit, and build (pull_request) Successful in 2m38s
CI / Backend migration, tests, and audit (pull_request) Successful in 8m46s
CI / Synthetic session harness (no GPU, no LLM) (pull_request) Successful in 15m39s
834cc28241
The session page's elapsed timer (#381) anchored on sessions.updated_at
because the pipeline recorded no start time, so any unrelated edit to the
session reset it.

Adds sessions.audio_processing_started_at, stamped wherever the status
becomes `processing`: the bot audio hand-off and the GM and admin retry
endpoints. Deliberately not stamped when process_audio picks the job up:
the task re-runs on every Celery retry while the status stays
`processing`, and the GM sees one continuous run.

The migration backfills the column from updated_at for sessions already
processing, so an in-flight timer does not jump on upgrade. The
stuck-task watchdog still uses updated_at; switching it would make its
8h cutoff count queue and retry time, which wants its own decision.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
claude-bot deleted branch feat/534-audio-processing-started-at 2026-09-14 03:26:03 +00:00
Sign in to join this conversation.
No description provided.