Upload worker logs nothing until the job ends: no start, phase, engine or adjudication lines #43

Closed
opened 2026-10-02 05:30:21 +00:00 by mathias · 2 comments
Owner

Found 2026-10-02 during the ADR-034 blind check, with a 64-minute recording in flight. Sibling of #42 (progress in the UI); this one is the operator side and stands alone.

Observed. From the moment the process logged serving web ui until the job ended, the server log had 7 lines, none about the upload. A 10+ minute job was visible only from outside: spool files appearing, iguana CPU, and ollama /api/ps showing gemma4:31b loaded. Nothing in the log said which phase it was in, or that it was alive.

Cause (internal/uploads/worker.go). The worker logs only on error (upload: start transcribing, temp wav, convert, transcribe, store transcript) and once on success (upload transcribed). There is no line for: job picked up, probe result, audio extracted (duration, WAV size), engine A started/finished (endpoint, wall time), engine B started/finished, reconcile started (dispute count), adjudication progress, or saving. internal/adapters/transcribe/ensemble.go and internal/reconcile/reconcile.go log nothing at all, including when an engine soft-fails and the pipeline degrades to single-engine. That degradation is visible to the user on the page but not to the operator.

Wanted

  • one INFO line per phase transition and per engine call, with the upload id, endpoint and elapsed time
  • reconcile: disputes found, auto-resolved, then a periodic adjudicated n/N line (every N items or every minute, not per item) and the breaker tripping at 3 consecutive errors
  • a WARN when an engine soft-fails and the result degrades, with the error kind (typed, not a provider string)
  • a long-running-job line (for example every 5 minutes) saying the job is still in phase X, so a silent hang is distinguishable from a quiet job

Privacy constraint. Public repo, private content. Log ids, counts, durations, endpoints and error kinds only. Never the transcript, the disputed words or the filename. There is already a precedent: uploadFailure logs the reason only. A test should assert no log line contains a word from a synthetic transcript.

Test. Capture slog output in the worker/ensemble tests and assert the phase lines appear in order for a successful two-engine job, and that a soft-failed engine produces the WARN.

The log lines and the UI indicator in #42 should come from the same phase transitions so they cannot disagree.


Created via git-mcp on behalf of @mathias

Found 2026-10-02 during the ADR-034 blind check, with a 64-minute recording in flight. Sibling of #42 (progress in the UI); this one is the operator side and stands alone. **Observed.** From the moment the process logged `serving web ui` until the job ended, the server log had 7 lines, none about the upload. A 10+ minute job was visible only from outside: spool files appearing, iguana CPU, and `ollama /api/ps` showing `gemma4:31b` loaded. Nothing in the log said which phase it was in, or that it was alive. **Cause (`internal/uploads/worker.go`).** The worker logs only on error (`upload: start transcribing`, `temp wav`, `convert`, `transcribe`, `store transcript`) and once on success (`upload transcribed`). There is no line for: job picked up, probe result, audio extracted (duration, WAV size), engine A started/finished (endpoint, wall time), engine B started/finished, reconcile started (dispute count), adjudication progress, or saving. `internal/adapters/transcribe/ensemble.go` and `internal/reconcile/reconcile.go` log nothing at all, including when an engine soft-fails and the pipeline degrades to single-engine. That degradation is visible to the user on the page but not to the operator. **Wanted** - one INFO line per phase transition and per engine call, with the upload id, endpoint and elapsed time - reconcile: disputes found, auto-resolved, then a periodic `adjudicated n/N` line (every N items or every minute, not per item) and the breaker tripping at 3 consecutive errors - a WARN when an engine soft-fails and the result degrades, with the error kind (typed, not a provider string) - a long-running-job line (for example every 5 minutes) saying the job is still in phase X, so a silent hang is distinguishable from a quiet job **Privacy constraint.** Public repo, private content. Log ids, counts, durations, endpoints and error kinds only. Never the transcript, the disputed words or the filename. There is already a precedent: `uploadFailure` logs the reason only. A test should assert no log line contains a word from a synthetic transcript. **Test.** Capture slog output in the worker/ensemble tests and assert the phase lines appear in order for a successful two-engine job, and that a soft-failed engine produces the WARN. The log lines and the UI indicator in #42 should come from the same phase transitions so they cannot disagree. --- _Created via git-mcp on behalf of @mathias_
Author
Owner

Built on PR #39 (head 7029dd1), per ADR-035. Closes on merge.

Done: the worker, ensemble and reconciler log through the same progress.Tracker that writes the page's phases. One INFO line per phase transition, step progress at most once a minute for the counted phase, a reconciled line with the counts, WARN with the error on a soft-failed engine or a tripped breaker, and a "still running" line every 5 minutes. Every line carries upload=<id>. A test captures the log of a job whose transcript contains a marker word and asserts neither it nor the spool path appears. A heartbeat goroutine runs independently of engine calls and is awaited at job end.

Limit: error text from a gateway can still appear in a WARN (err=), as it did before; it is not transcript content, but it is provider text. Typed error kinds in the log remain a follow-up if wanted.


Created via git-mcp on behalf of @mathias

Built on PR #39 (head `7029dd1`), per ADR-035. Closes on merge. Done: the worker, ensemble and reconciler log through the same `progress.Tracker` that writes the page's phases. One INFO line per phase transition, `step progress` at most once a minute for the counted phase, a `reconciled` line with the counts, WARN with the error on a soft-failed engine or a tripped breaker, and a "still running" line every 5 minutes. Every line carries `upload=<id>`. A test captures the log of a job whose transcript contains a marker word and asserts neither it nor the spool path appears. A heartbeat goroutine runs independently of engine calls and is awaited at job end. Limit: error text from a gateway can still appear in a WARN (`err=`), as it did before; it is not transcript content, but it is provider text. Typed error kinds in the log remain a follow-up if wanted. --- _Created via git-mcp on behalf of @mathias_
Author
Owner

Merged in PR #39 (squash 4a20670), released as v0.31.0. Phase logging through the single progress tracker, a heartbeat that is awaited, kinds instead of error text, and a test that no log line carries transcript text or the spool path. Closing.


Created via git-mcp on behalf of @mathias

Merged in PR #39 (squash `4a20670`), released as **v0.31.0**. Phase logging through the single progress tracker, a heartbeat that is awaited, kinds instead of error text, and a test that no log line carries transcript text or the spool path. Closing. --- _Created via git-mcp on behalf of @mathias_
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: mathias/tapir#43