Skip to content

Drain the worker on deploy and make interrupted or malformed runs fail cleanly - #155

Merged
demegire merged 1 commit into
mainfrom
fix/prod-log-p1
Sep 25, 2026
Merged

demegire merged 1 commit into
mainfrom
fix/prod-log-p1

Conversation

@demegire

Copy link
Copy Markdown
Contributor

P1 from the 09-23..09-25 prod log review: deploys no longer kill in-flight model calls, and interrupted or malformed runs now fail once with a clear reason instead of wedging or retrying three times.

4. Deploy drain (in-process)

Why: every deploy logged will wait 0:00:00 before cancelling activities and Cancel N running task(s). The Codex relay runs in the same FastAPI app and stopped before the worker drained. At 01:18 this killed a project.weekly_brief in the middle of a model call.

  • Both Workers get graceful_shutdown_timeout, set by the new setting worker_graceful_shutdown_seconds (TIN_LITE_WORKER_GRACEFUL_SHUTDOWN_SECONDS, default 300).
  • New tin_lite/serving.py with DrainingServer(uvicorn.Server). uvicorn 0.52's handle_exit is a synchronous signal.signal handler, so on the first SIGTERM/SIGINT it only schedules a task with loop.call_soon_threadsafe. That task awaits runtime.worker.shutdown() (stop polling, then drain), bounded by the grace period + 60s. Only after that does it set should_exit, and then uvicorn's existing timeout_graceful_shutdown=20 HTTP drain runs. HTTP and the relay keep serving during the drain.
    • Repeated SIGTERMs during the drain are absorbed, because systemd and the uv run parent can both deliver one. A second SIGINT stops waiting.
  • WorkerGroup.shutdown() is now idempotent: one shielded task shared by every caller, so the later worker.shutdown() in the main.py lifespan returns at once. It also no longer hangs on a worker whose run() failed before it started. I checked this against temporalio 1.32: Worker.shutdown() waits on a completion event that only _run sets.
  • infra/install_switchboard.sh unit: TimeoutStopSec=420.

Operator note: changing the live systemd unit on the VM is a separate prod configuration change and needs explicit authority at deploy time. This PR doesn't touch the VM. Until the unit is updated, systemd's default 90s stop timeout will SIGKILL a drain that runs longer. With the drain, systemctl restart in activate_release.sh can take up to about 6 minutes while activities finish.

5. Effect receipts survive cancellation and never wedge a retry

Why: attempts 2 and 3 failed with External request already observed; recover its owning effect. The owning effect stayed started because CancelledError skips except Exception.

  • Weekly brief, answer page, project memory (memory_commit) and project scan (scan_commit) now catch BaseException. They record fail_effect through a helper that finishes the write even if cancelled again, before the effect lock releases its connection, and then re-raise.
  • Before the model call, if an observation for that step already exists, the step raises a non-retryable ApplicationError of type ModelRequestInterrupted: "…: the model request was interrupted and was not repeated; start the run again". This follows the visibility recovery pattern.
  • usage_capture.begin_observation raises ObservationAlreadyRecorded(RuntimeError), keeping the same message. These sites convert it to the same terminal error.
  • Receipts wedged as started by the current release recover the same way on retry.

6. brand.capture method

Why: persist_codex_procedure_artifact failed 3x with Unsupported brand assessment method, and CONTRACT.md invited variation.

  • brand_contract.assessment now owns METHOD. A missing or variant method is normalized, with a note (logged at capture; shown in the brand read diagnostics). A method that isn't an object is rejected.
  • A ValueError from validate_pair in _procedure_companions becomes a non-retryable BrandCaptureInvalid.
  • CONTRACT.md now states the exact literal. Packet-only coverage goes in evidence_status and the findings, not in the method. Package version bumped to 1.0.2.

7. Visibility question IDs

Why: two runs failed with VisibilityProtocolError: visibility question ID is invalid.

  • The panel schema's question id gets pattern: ^[a-z0-9_-]{1,32}$.
  • prepare_panel normalizes IDs before validation, before panel_hash, and before the activity derives answer receipt keys from the stored panel. It lowercases, replaces other characters with _, truncates to 32 and de-duplicates with -2, -3. The result is deterministic: replaying the same saved response gives the same IDs, so receipt keys stay stable.
  • Adjudication question_id and evidence_question_ids written in the old spelling are mapped onto the panel IDs.

8. commit_project_changes RefUpdateError

Why: the MCP tool raised an unmapped pierre_storage RefUpdateError ("no changes to commit"). project_files didn't record a failure and mcp_errors masked it.

  • code_storage.commit_project_changes still runs the lost-ack check first. After that, a RefUpdateError is mapped:
    • "no changes" → ValueError("no changes: files already match expected_revision"), shown in MCP as invalid:.
    • conflict/412 → RuntimeError("canonical project state changed before file commit"), which becomes StaleProjectRevisionError, shown as conflict:.
    • Other reasons, such as unavailable, → a recorded storage_failed RuntimeError. These are transient failures, so they are not reported as a stale revision.
  • ProjectFileService.commit now also fails the change row on ValueError, so rows no longer stay started.

Tests

  • New:
    • tests/test_worker_drain.py: a fake worker proves the exit handler awaits the drain before should_exit, a real uvicorn keeps serving HTTP during the drain, and repeated signals, timeouts and WorkerGroup idempotency behave.
    • tests/test_effect_interruption.py (Postgres): CancelledError in the middle of execute() for weekly brief and answer page leaves the receipt failed; the retry is non-retryable with the new message and never calls the model; a legacy started receipt recovers the same way.
    • tests/test_project_commit_errors.py.
  • Added cases in tests/test_brand_capture.py and tests/test_visibility_audit.py.
  • Updated tests/test_cli_serve.py and tests/test_runtime.py (asserts the 5-minute grace period), and the fake get_effect(conn=) in test_answer_page, test_project_memory and test_scan_report.
  • uv run pytest -n auto against a disposable Postgres: 3375 passed, 49 skipped, 3 failed. The 3 failures are tests/test_delimited_viewer.py, a known Node 18 issue on this host; CI uses Node 22. test_temporal_replay.py passes, and no workflow code changed.
  • ruff format --check, ruff check and lint-imports are clean. tin-lite validate-community: 18 of 18 packages valid.

Not merged or deployed.

🤖 Generated with Claude Code

https://claude.ai/code/session_01Ua8Ysd7jtjWKHGg9DrUs4n

…l cleanly

- SIGTERM now drains the Temporal worker (graceful_shutdown_timeout, default
  300s via TIN_LITE_WORKER_GRACEFUL_SHUTDOWN_SECONDS) while HTTP and the Codex
  relay keep serving; uvicorn's own 20s shutdown follows. WorkerGroup shutdown
  is idempotent and no longer hangs on a worker that never started.
  install_switchboard.sh sets TimeoutStopSec=420.
- Weekly brief, answer page, project memory and project scan receipts are
  marked failed even on cancellation, and a retry whose model request was
  already observed fails non-retryably instead of "External request already
  observed". begin_observation raises ObservationAlreadyRecorded.
- brand.capture: code owns the assessment method; variants are normalized
  with a note, non-objects are rejected, and an invalid pair fails once.
- visibility.audit: question IDs are normalized deterministically before
  validation and receipt keys; adjudication references follow.
- commit_project_changes maps code.storage RefUpdateError to invalid (no
  changes), conflict (stale ref) or a recorded storage failure.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Ua8Ysd7jtjWKHGg9DrUs4n
@demegire
demegire requested a review from a team as a code owner September 25, 2026 10:43
@demegire
demegire merged commit 649dc3e into main Sep 25, 2026
6 checks passed
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