job-scheduled-run: job timeouts are not enforced in the durable record — a timed-out run persists status:'success'

[huangyiirene]

Symptom

A job declared with timeout: 2000 whose handler sleeps 10 s records sys_job_run.status: 'success' with duration_ms ~10000 (five times the declared timeout), and sys_job reads last_status: success, failure_count: 0. Expected per JobExecutionStatus / #3494: run status timeout, counted as a failure. The scheduler does abandon and retry (a retryPolicy variant fired attempt 2 at timeout+backoff), yet both attempts still landed as success rows. Relatedly, sys_job_run.attempt reads 1 for every retry.

Root cause

In packages/services/service-job/src/db-job-adapter.ts, schedule() (~line 80) computes const wrapped = this.wrap(name, handler, 'schedule') and passes wrapped into IntervalJobAdapter / CronJobAdapter. Those adapters apply the timeout guard via run-with-policy.ts withTimeout → Promise.race([run(), guard]) (~line 50) — so the guard races the recording wrapper, not the raw handler. When the guard rejects, wrap()'s inner await handler(ctx) (~line 200) is still pending on the un-cancellable handler; when it finally resolves, wrap() writes finishRun(runId, 'success', ...) (~line 211). The timeout status the adapters compute lives only in the in-memory JobExecution list that sys_job_run never reads — which is why interval-job-adapter.test.ts's in-memory "records status 'timeout'" assertion stays green while the persisted record an operator sees says success. The same seam explains the hardcoded attempt: 1 in startRun (~line 233).

Stale-premise check: db-job-adapter.ts, run-with-policy.ts, interval-job-adapter.ts, cron-job-adapter.ts all have zero diff between the 92f26f75 pin and origin/main — not fixed upstream. (Same timeout-guard-wins-race-but-recorder-still-resolves class as the closed #4875 / #4813 in HealthMonitor; distinct subsystem.)

Reproduction

1. Declare a job with timeout: 2000 whose handler sleeps 10 s; let it fire.
2. Read sys_job_run and sys_job.

Expected: run status timeout, sys_job.failure_count incremented. Actual: status: 'success', duration_ms ~10000, failure_count: 0; retries also persist as success and attempt stays 1.

Source

Extracted from the QA run #7690 (framework 92f26f7, console 09987b680).

[huangyiirene]

Claim: PM loop round 1
Session: session_01JVfWSQN9RDDGwdVSmMc29x
Branch: claude/issue-7734-job-timeout-durable-status
Worktree: cloud session's own clone (mode:cloud)
Domain: domain:services
File surface: packages/services/service-job/src/** (db-job-adapter.ts, run-with-policy.ts, interval-job-adapter.ts, cron-job-adapter.ts + their tests).
Container & model: M (timing-seam rework across the wrap/race boundary), mode:cloud, model: opus
Serial constraints cleared: ⚠️ adjacent same-file predecessor already merged: #7446 (commit 05ac83d, 2026-08-10 12:47Z) reworked db-job-adapter.ts (+72), cron-job-adapter.ts, interval-job-adapter.ts to map a degraded outcome into sys_job_run.status, adding db-job-adapter.degraded-outcome.test.ts. QA pin 92f26f75 (08-11 08:51Z) postdates it, so the symptom was observed WITH #7446 in place — premise intact, but the fix must build on that mapping seam, not clobber it. No in-flight PR touches service-job.

---

Generated by Claude Code

[huangyiirene]

{
  "issue": 7734,
  "repo": "objectstack-ai/objectstack",
  "branch": "claude/issue-7734-job-timeout-durable-status",
  "head_sha": "f3bbe14",
  "pr": 7784,
  "pr_url": "https://github.com/objectstack-ai/objectstack/pull/7784",
  "pr_state": "draft",
  "premise_still_valid": true,
  "premise_evidence": [
    "db-job-adapter.ts:81 on origin/main (7a8476f) — `const wrapped = this.wrap(name, handler, 'schedule')` is handed to IntervalJobAdapter/CronJobAdapter at lines 84-91 together with `options`, exactly as the filer described.",
    "interval-job-adapter.ts:157 and cron-job-adapter.ts:158 — `runWithPolicy(record.name, () => record.handler(...), record.options)`: the timeout guard wraps the RECORDER, not the raw handler.",
    "run-with-policy.ts:50 — `Promise.race([run(), guard])`; the losing branch is abandoned, not cancelled. wrap()'s inner `await handler(ctx)` (line 200) stays pending and its eventual resolution reaches finishRun(runId,'success') at line 211.",
    "The `timeout` status is computed only at interval-job-adapter.ts:171 / cron-job-adapter.ts:169, into the in-memory JobExecution list; sys_job_run never reads it.",
    "startRun hardcoded `attempt: 1` at line 233 — same seam, the recorder had no attempt number.",
    "#7446's degraded-outcome mapping is present and intact on origin/main; this change builds on it and its whole suite stays green."
  ],
  "fixed_at_the_seam_the_issue_named": true,
  "root_cause": "DbJobAdapter recorded from OUTSIDE the timeout policy. The party that observes a timeout (runWithPolicy's withTimeout race) and the party that writes the durable record (DbJobAdapter.wrap) were different, and the recorder was the thing being raced — so a timed-out run's row was settled by whatever the abandoned, uncancellable handler eventually did.",
  "fix_summary": "Moved the recording INSIDE the policy. run-with-policy.ts gains an optional 4th arg — a per-attempt JobAttemptRecorder (onAttemptStart / onAttemptSettled, reporting `timedOut` at the instant the guard fires) — and its two former paths (with/without retryPolicy) are unified into one loop so the recorder is driven identically either way. DbJobAdapter.wrap now runs the handler under runWithPolicy and records from those callbacks; the timer adapter receives a registration with retryPolicy/timeout stripped (withoutPolicy()), since the wrapper above it applies both. The abandoned attempt's late value loses the race and reaches no observer, so the overwrite has no code path left; a per-run `settled` latch keeps one-terminal-write-per-row explicit as a second lock.",
  "behaviour_changes": [
    "sys_job_run.status = 'timeout' (was 'success') with the guard message in `error`",
    "sys_job_run.duration_ms measures the abandoned attempt, not the handler's full runtime",
    "sys_job.last_status = 'timeout' and failure_count +1 — a run that never finished is a failure",
    "sys_job_run.attempt carries the real attempt number; a retry lands 2",
    "replay()'s synthetic row mirrors ANY terminal status (was: degraded only), so a timed-out replay no longer pairs an honest row with a success one"
  ],
  "files_changed": [
    "packages/services/service-job/src/run-with-policy.ts",
    "packages/services/service-job/src/db-job-adapter.ts",
    "packages/services/service-job/src/db-job-adapter.timeout.test.ts (new, 10 cases)",
    ".changeset/job-timeout-durable-record.md (patch)"
  ],
  "tests": {
    "new_file": "packages/services/service-job/src/db-job-adapter.timeout.test.ts",
    "asserts_durable_record_only": true,
    "cases": [
      "persists sys_job_run.status 'timeout', not 'success', with the guard message in error",
      "sys_job.last_status 'timeout' + failure_count 1 + run_count 1",
      "duration_ms is the abandoned attempt's, bounded below the handler's runtime",
      "OVERWRITE RACE: guard fires -> assert timeout -> let the handler run to completion (asserted resolved) -> row still 'timeout', still one row, counters unmoved",
      "retried timeout persists rows [attempt 1, attempt 2], both 'timeout', failure_count 2",
      "retried failure numbers attempts [1, 2, 3]",
      "ADDITIVITY: a handler inside its timeout still records success / attempt 1",
      "in-memory getExecutions() and the persisted row report the same verdict; listExecutionsByStatus('timeout') finds it",
      "replay of a timing-out job writes no success row",
      "the policy still applies through an INJECTED CronJobAdapter (guards withoutPolicy() against outrunning the wrapper that replaces it)"
    ],
    "reverse_verification": "With db-job-adapter.ts + run-with-policy.ts reverted to origin/main and the new test file kept: 9 of 10 fail (expected 'running' to be 'timeout'; expected [1,1] to deeply equal [1,2]; expected ['success','running'] to deeply equal ['timeout','timeout']; ...). The 10th is the additivity case, correctly green both before and after."
  },
  "gates": {
    "build_closure": "pass — turbo run build --filter=@objectstack/service-job... (6/6)",
    "package_suite": "pass — vitest run in service-job: 8 files, 66 tests, including #7446's db-job-adapter.degraded-outcome.test.ts",
    "typecheck": "pass — turbo run typecheck --filter=@objectstack/service-job",
    "docs_audit_scope": "pass — pnpm check:docs-audit-scope",
    "downstream_consumers": "pass — runtime/app-plugin.jobs.test.ts (5) + service-automation wait-node.test.ts & wait-node-degraded-run.test.ts (29)",
    "changeset": "present — .changeset/job-timeout-durable-record.md (patch, @objectstack/service-job)",
    "lint_farm": "not run locally, per the dispatch contract — CI owns it",
    "ci": "in_progress — not polled; PM owns CI convergence and the ready-flip"
  },
  "decisions_taken": [
    "Recorder-inside-the-policy over a status-latch-only patch: a latch alone would leave the recorder still racing the guard, so duration_ms and the attempt number would stay wrong even if the status stuck.",
    "Stripping retryPolicy/timeout from the registration handed downstream, rather than leaving the timer adapter to apply them a second time — a second budget would race the whole retry sequence and abandon retries mid-flight. Every other option still flows through; a regression test fires a cron-scheduled run through an injected CronJobAdapter to pin it.",
    "Attempt numbering comes from runWithPolicy's own loop counter rather than a per-job counter in the adapter, because only the policy knows where one fire's attempt sequence begins and ends.",
    "timeout bumps failure_count (unlike degraded, which does not): the run never finished and the policy retries it. This mirrors the issue's 'counted as a failure' expectation and #7446's opposite ruling for degraded."
  ],
  "open_questions": [
    "replay()'s synthetic row mapping was widened from degraded-only to any terminal status. Judged in-scope (same defect — a durable row reading 'success' for a run that timed out — wearing a replay tag) and it keeps #7446's replay-of-degraded test green. Flagging in case the PM reads replay as a separate card.",
    "Manual trigger()/replay() runs still record trigger:'schedule' because wrap() is built once at schedule time with that default. Pre-existing, untouched, not part of this card's symptom."
  ],
  "scope_left_out": "none — timeout status, failure_count, attempt numbering and the overwrite race are all covered."
}

---

Generated by Claude Code

[huangyiirene]

ACCEPT — PR #7784 (services seat review, session session_01JVfWSQN9RDDGwdVSmMc29x).

What shipped: the durable record is now written by the party that observes the timeout. runWithPolicy gained a per-attempt recorder (onAttemptStart/onAttemptSettled with timedOut at guard-fire time); DbJobAdapter.wrap runs the handler under the policy and records from those callbacks, with a per-run settled latch as a second lock. withoutPolicy() strips retryPolicy/timeout from the registration handed to timer adapters so the budget is applied exactly once. sys_job_run.status lands timeout (guard message in error), failure_count increments, attempt carries the real number, and replay()'s synthetic row now mirrors any terminal status.

Review notes:

• All 4 changed files inside the claimed surface; changeset present; no content/docs/releases/ edits.
• Tests assert durable-record cells only, including the overwrite race head-on (guard fires → handler later resolves → row stays timeout). Reverse verification: 9/10 fail on reverted seams; the 10th is the additivity pin, correctly green both ways.
• fix(service-job,service-automation): map a degraded job outcome to sys_job_run.status instead of success (#5548) #7446's degraded-outcome seam is built on, not clobbered — its suite stayed green; the replay-mapping widening is accepted as in-scope (same defect wearing a replay tag).
• The pre-existing trigger:'schedule' attribution on manual trigger() runs (noted in the report) is out of scope here; it matches what fix(service-automation): populate trigger.recordId and persist run trigger attribution to sys_automation_run #7595 addressed for automation runs — left unfiled since it may be intended; flagging for the next reader.

PR-side gate jobs all green (ESLint / TypeScript Type Check / Test Core ×3). Marked ready and queued at ~15:1xZ. ⚠️ Landing note: main is currently red in the queue's full-suite build (#7793, unrelated to this diff) — if the queue kicks this PR with that signature, it will be re-queued once #7793's stopgap lands.

---

Generated by Claude Code