#1727 · Pre-turn thread usage snapshots are dropped as "orphan thread-state snapshot with no stored turn/started"
TL;DR
Plain-language framing. Every event the Codex provider produces for a bb thread is tagged with a turn id. The server refuses to store most turn-tagged events until it has stored that turn's turn/started; two "thread-state snapshot" events (thread/tokenUsage/updated, thread/contextWindowUsage/updated) are the exception: instead of failing the batch they are silently discarded and a warning is logged. The bb Codex plugin runs one codex app-server child per thread and prefixes every Codex turn id with a per-session nonce (bt<entropy>-<serial>-) before it reaches bb; each resume or fork of a thread is a new session with a new prefix.
What the user sees. Two Dropped orphan thread-state snapshot with no stored turn/started warnings in the server log every time a Codex thread is resumed (archive→unarchive, daemon restart, or plain idle reaping after 30 min) and on the first turn of every native fork. Nothing is visibly broken in the app.
What is actually happening. codex app-server (0.147.0) replays the rollout's last-turn token usage on thread/resume and thread/fork, scoped to that previous turn's Codex id, before any new turn exists (verified with a raw JSON-RPC probe). The bridge stamps that id with the new session's prefix, so on resume the same Codex turn arrives under a bb turn id different from the one its turn/started was stored under, and on fork it names a turn the forked bb thread never had. Either way the server's orphan rule fires. The drop is deliberate at the server layer (there is a comment and a test for the fork case); the surprising part is that resume also hits it, which is a side effect of the per-session id prefix introduced with the bridge protocol (#1640) — the previous adapter forwarded raw Codex turn ids, which matched.
Impact. On resume the dropped snapshot is byte-for-byte the value already stored for that turn (I compared payloads), so nothing is lost — it is log noise, but it fires routinely. On fork the forked thread simply has no context-window number until its own first turn completes; the parent's inherited context usage (~20k of 258k tokens here) is discarded although the domain scope policy would let it be stored thread-scoped. Answer to the issue's question: the server should keep dropping unknown-turn snapshots (buffering would re-introduce the batch-wedging fork bug this rule was written for); the Codex bridge should stop emitting turn-scoped replays for turns it never started — thread-scope the context usage, drop the duplicate token usage. A prototype of that (bridge-only, ~20 lines) passes the full codex plugin suite.
Claims vs findings
| Claim | Status | Evidence |
|---|---|---|
Server warns Dropped orphan thread-state snapshot with no stored turn/started for thread/tokenUsage/updated and thread/contextWindowUsage/updated on codex resume | Verified | Live: archive→unarchive→thread tell on thr_gfmnau443m logged both warnings; also after a dev-instance restart forced a second resume. 1727/server.log, lines below. |
| Same on the first turn of a forked codex thread | Verified | Fork thr_3xey7gdhwn with a first prompt: both warnings, turn id bte3e286cb-1-01a013e5-8295… = parent's last Codex turn re-prefixed with the fork session's nonce. |
Snapshots arrive "before the turn's turn/started is stored" | Imprecise | They do not belong to the upcoming turn at all: they are Codex's replay of the previous turn's usage, emitted right after thread/resume/thread/fork and before any turn/start request (raw app-server probe below). There is no ordering race with turn/started persistence. |
| Usage lands afterwards; impact is a transiently missing number, not persistent loss | Verified, with nuance | Resume: dropped payload equals the already-stored snapshot for that turn (seq 27 vs dropped, both total 39970 / last 19993), so nothing is even transiently missing. Fork: the forked thread has no context-window usage until its first turn completes. |
Drop site is apps/server/src/internal/events.ts ~L949 | Verified | Log site events.ts#L941-L951; the decision is in packages/db/src/data/events.ts#L381-L430. |
| Pre-existing, verified on origin/main | Partly | The server-side drop rule dates from #85 and the fork case is by design (tested). The resume case only exists since the bridge's per-session id prefix landed with #1640 (c5b53caab, merged 6 minutes before this issue was filed); the legacy adapter passed raw Codex turn ids, which match across sessions. Nothing on origin/main after the base commit touches this (checked 16ceb3a54..origin/main). |
Environment
- bb
16ceb3a54(main, 2026-08-18), package version 0.38.0. Worktree/home/sawyer/projects/bb/.claude/worktrees/wf_242c3e11-a10-33. Note: the worktree was created ata108fa7ef; I checked out16ceb3a54before the live runs (relevant files are unchanged between the two apart from unrelated item-id bounding). - Dev instance: app
:12350, server:20350, host daemon:28350, data dir/home/sawyer/.bb-dev/projects-bb-.claude-worktrees-wf_242c3e11-a10-33-3a3a06c6efd6, hosthost_675q2rjmvs. - Linux 7.0.0-29-generic, node v24.18.0, pnpm 9.15.0, codex-cli 0.147.0 (provider
codex, default model). - Project
proj_9u4kg498pm(local path/tmp/bb-1727-probe/scratch), threadsthr_gfmnau443m(resume case) andthr_3xey7gdhwn(fork case). - Server-log instrumentation used for the second run (adds
scope+datato the warn line): 1727/repro/server-log-instrumentation.diff. Not required to see the warning, only to see which turn id was dropped.
Minimal reproduction
A. What codex app-server does on resume / fork (no bb involved)
Script 1727/repro/codex-app-server-probe.mjs drives three codex app-server children over stdio: (A) thread/start + one tiny turn, (B) thread/resume of that thread in a fresh process, then a turn, (C) thread/fork in a fresh process, then a turn. Run: node codex-app-server-probe.mjs /path/to/any/git/repo. Trimmed output (full: 1727/codex-app-server-probe.log):
[A:start] ->REQ initialize {"clientInfo":{"name":"bb-probe","version":"1.0.0","title":null},"capabilities":{"experimentalApi":true}}
[A:start] ->REQ thread/start {"cwd":"/tmp/bb-1727-probe/scratch","approvalPolicy":"never","sandbox":"read-only","ephemeral":false,"experimentalRawEvents":true}
[A] threadId=01a013de-875f-7df1-b9c4-122b3b21a91e
[A:start] ->REQ turn/start {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","input":[{"type":"text","text":"Reply only with ok."}]}
[A:start] <-NOTIF thread/started {}
[A:start] <-NOTIF turn/started {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","turn":"01a013de-8818-7b90-ba09-a209034b106f"}
[A:start] <-NOTIF item/started {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[A:start] <-NOTIF item/completed {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[A:start] <-NOTIF item/started {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[A:start] <-NOTIF item/completed {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[A:start] <-NOTIF thread/tokenUsage/updated {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","total":16378,"last":16378}
[A:start] <-NOTIF turn/completed {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","turn":"01a013de-8818-7b90-ba09-a209034b106f"}
[B:resume] ->REQ initialize {"clientInfo":{"name":"bb-probe","version":"1.0.0","title":null},"capabilities":{"experimentalApi":true}}
[B] --- sending thread/resume ---
[B:resume] ->REQ thread/resume {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","cwd":"/tmp/bb-1727-probe/scratch","approvalPolicy":"never","sandbox":"read-only"}
[B:resume] <-NOTIF thread/tokenUsage/updated {"turnId":"01a013de-8818-7b90-ba09-a209034b106f","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","total":16378,"last":16378}
[B] --- sending turn/start on resumed thread ---
[B:resume] ->REQ turn/start {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","input":[{"type":"text","text":"Reply only with ok."}]}
[B:resume] <-NOTIF turn/started {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","turn":"01a013de-a00b-7c31-bc76-6a2e24831f63"}
[B:resume] <-NOTIF item/started {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[B:resume] <-NOTIF item/completed {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[B:resume] <-NOTIF item/started {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[B:resume] <-NOTIF item/completed {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e"}
[B:resume] <-NOTIF thread/tokenUsage/updated {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","total":37194,"last":20816}
[B:resume] <-NOTIF turn/completed {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","turn":"01a013de-a00b-7c31-bc76-6a2e24831f63"}
[C:fork] ->REQ initialize {"clientInfo":{"name":"bb-probe","version":"1.0.0","title":null},"capabilities":{"experimentalApi":true}}
[C] --- sending thread/fork ---
[C:fork] ->REQ thread/fork {"threadId":"01a013de-875f-7df1-b9c4-122b3b21a91e","cwd":"/tmp/bb-1727-probe/scratch","approvalPolicy":"never","sandbox":"read-only"}
[C] forked threadId=01a013de-b0f5-72c0-aaf4-200bd9720171
[C:fork] <-NOTIF thread/tokenUsage/updated {"turnId":"01a013de-a00b-7c31-bc76-6a2e24831f63","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171","total":37194,"last":20816}
[C:fork] <-NOTIF thread/started {}
[C] --- sending turn/start on forked thread ---
[C:fork] ->REQ turn/start {"threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171","input":[{"type":"text","text":"Reply only with ok."}]}
[C:fork] <-NOTIF turn/started {"threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171","turn":"01a013de-b762-7193-83c7-d605305511e5"}
[C:fork] <-NOTIF item/started {"turnId":"01a013de-b762-7193-83c7-d605305511e5","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171"}
[C:fork] <-NOTIF item/completed {"turnId":"01a013de-b762-7193-83c7-d605305511e5","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171"}
[C:fork] <-NOTIF item/started {"turnId":"01a013de-b762-7193-83c7-d605305511e5","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171"}
[C:fork] <-NOTIF item/completed {"turnId":"01a013de-b762-7193-83c7-d605305511e5","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171"}
[C:fork] <-NOTIF thread/tokenUsage/updated {"turnId":"01a013de-b762-7193-83c7-d605305511e5","threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171","total":58026,"last":20832}
[C:fork] <-NOTIF turn/completed {"threadId":"01a013de-b0f5-72c0-aaf4-200bd9720171","turn":"01a013de-b762-7193-83c7-d605305511e5"}
Look at the first thread/tokenUsage/updated after thread/resume (turnId 01a013de-8818… = the turn from process A) and after thread/fork (turnId 01a013de-a00b… = the parent's last turn, on the new thread id 01a013de-b0f5…). Both precede any turn/start.
B. Live bb: resume and fork on a codex thread
pnpm install --frozen-lockfile --prefer-offline && pnpm exec turbo run build && scripts/bb-dev-app current; note Server URL and Data dir.export BB_SERVER_URL=http://localhost:20350(yours will differ).CLI="node packages/scripts/dist/commands/run-cli.js"(after onepnpm bb:dev). UnsetBB_THREAD_IDif your shell has one, otherwisethread tellfails withSender thread is invalid.- Create a scratch git repo and a project:
curl -s -X POST $BB_SERVER_URL/api/v1/projects -H 'content-type: application/json' -d '{"name":"qa","source":{"type":"local_path","path":"/tmp/bb-1727-probe/scratch","hostId":"<id from $CLI machine list>"}}' - Spawn and finish one codex turn:
$CLI thread spawn --project <proj> --provider codex --permission-mode accept-edits --prompt "Reply only with ok." --json;$CLI thread wait <thr>. - Resume path:
$CLI thread archive <thr>;$CLI thread unarchive <thr>;$CLI thread tell <thr> "Reply only with ok.";$CLI thread wait <thr>. (Any session release works the same: daemon restart, or waiting >30 min for idle reaping — IDLE_PROVIDER_SESSION_REAP_AFTER_MS.) - Fork path:
$CLI thread fork <thr> --workspace reuse --prompt "Reply only with ok." --json;$CLI thread wait <fork thr>. - Look:
grep orphan <Data dir>/logs/server.1.log
Expected: no warnings; a resume re-reporting the same turn's usage is a no-op, and a fork carries the parent's context usage. Actual (my run; the last four lines carry the instrumentation fields):
{"level":40,"time":1787040123396,"component":"server","eventType":"thread/tokenUsage/updated","threadId":"thr_gfmnau443m","sessionId":"hses_quxr3nes58","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
{"level":40,"time":1787040123396,"component":"server","eventType":"thread/contextWindowUsage/updated","threadId":"thr_gfmnau443m","sessionId":"hses_quxr3nes58","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
{"level":40,"time":1787040203422,"component":"server","eventType":"thread/tokenUsage/updated","threadId":"thr_gfmnau443m","scope":{"kind":"turn","turnId":"bt2e052653-1-01a013e4-49fe-7570-8577-320efd692a83"},"data":"{\"providerThreadId\":\"01a013e3-834a-7aa2-8e56-7ecfe0707907\",\"tokenUsage\":{\"total\":{\"totalTokens\":39970,\"inputTokens\":39960,\"cachedInputTokens\":0,\"outputTokens\":10,\"reasoningOutputTokens\":0},\"last\":{\"totalTokens\":19993,\"inputTokens\":19988,\"cachedInputTokens\":0,\"outputTokens\":5,\"reasoningOutputTokens\":0},\"modelContextWindow\":258400}}","sessionId":"hses_9dsxf4we3g","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
{"level":40,"time":1787040203422,"component":"server","eventType":"thread/contextWindowUsage/updated","threadId":"thr_gfmnau443m","scope":{"kind":"turn","turnId":"bt2e052653-1-01a013e4-49fe-7570-8577-320efd692a83"},"data":"{\"providerThreadId\":\"01a013e3-834a-7aa2-8e56-7ecfe0707907\",\"contextWindowUsage\":{\"usedTokens\":19993,\"modelContextWindow\":258400,\"estimated\":false}}","sessionId":"hses_9dsxf4we3g","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
{"level":40,"time":1787040239600,"component":"server","eventType":"thread/tokenUsage/updated","threadId":"thr_3xey7gdhwn","scope":{"kind":"turn","turnId":"bte3e286cb-1-01a013e5-8295-7f52-aeff-0dfc8b1bbe94"},"data":"{\"providerThreadId\":\"01a013e6-0f25-7b83-a8b0-6375b1492ccd\",\"tokenUsage\":{\"total\":{\"totalTokens\":59979,\"inputTokens\":59964,\"cachedInputTokens\":19200,\"outputTokens\":15,\"reasoningOutputTokens\":0},\"last\":{\"totalTokens\":20009,\"inputTokens\":20004,\"cachedInputTokens\":19200,\"outputTokens\":5,\"reasoningOutputTokens\":0},\"modelContextWindow\":258400}}","sessionId":"hses_9dsxf4we3g","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
{"level":40,"time":1787040239600,"component":"server","eventType":"thread/contextWindowUsage/updated","threadId":"thr_3xey7gdhwn","scope":{"kind":"turn","turnId":"bte3e286cb-1-01a013e5-8295-7f52-aeff-0dfc8b1bbe94"},"data":"{\"providerThreadId\":\"01a013e6-0f25-7b83-a8b0-6375b1492ccd\",\"contextWindowUsage\":{\"usedTokens\":20009,\"modelContextWindow\":258400,\"estimated\":false}}","sessionId":"hses_9dsxf4we3g","msg":"Dropped orphan thread-state snapshot with no stored turn/started"}
Cross-check against what is stored for the resumed thread (sqlite3 <Data dir>/bb.db): the second warning names Codex turn 01a013e4-49fe… under prefix bt2e052653-1-, but that turn's turn/started was stored under bt0b93b7ec-1- (seq 22), and its usage snapshot is already at seq 27 with the identical numbers:
sqlite> select sequence,type,turn_id,substr(data,1,120) from events where thread_id='thr_gfmnau443m' and type in ('turn/started','thread/tokenUsage/updated') order by sequence;
10|turn/started|bt4d7c8505-1-01a013e3-8409-7fb2-91fd-f37f0174c383|{"providerThreadId":"01a013e3-834a-7aa2-8e56-7ecfe0707907"}
15|thread/tokenUsage/updated|bt4d7c8505-1-01a013e3-8409-7fb2-91fd-f37f0174c383|{…"total":{"totalTokens":19977,…},"last":{"totalTokens":19977,…
22|turn/started|bt0b93b7ec-1-01a013e4-49fe-7570-8577-320efd692a83|{"providerThreadId":"01a013e3-834a-7aa2-8e56-7ecfe0707907"}
27|thread/tokenUsage/updated|bt0b93b7ec-1-01a013e4-49fe-7570-8577-320efd692a83|{…"total":{"totalTokens":39970,…},"last":{"totalTokens":19993,…
34|turn/started|bt2e052653-1-01a013e5-8295-7f52-aeff-0dfc8b1bbe94|{"providerThreadId":"01a013e3-834a-7aa2-8e56-7ecfe0707907"}
39|thread/tokenUsage/updated|bt2e052653-1-01a013e5-8295-7f52-aeff-0dfc8b1bbe94|{…"total":{"totalTokens":59979,…},"last":{"totalTokens":20009,…
Three sessions, three prefixes (bt4d7c8505-1-, bt0b93b7ec-1-, bt2e052653-1-): each resume spawns a new bridge/child pair, so both the entropy and the serial change. For the fork (thr_3xey7gdhwn) the dropped snapshot names 01a013e5-8295…, i.e. the parent's third turn, under the fork session's prefix bte3e286cb-1-; the forked thread's own events start at its first turn/started (bte3e286cb-1-01a013e6-0fe9…).
C. Repro test at the bridge (fails on 16ceb3a54)
File: plugins/provider-codex/src/bridge/bridge.resume-usage-replay.test.ts. It needs a 20-line opt-in in the test fixture fake-codex-app-server.mjs so that thread/resume for a usage-replay-* thread id replays last-turn usage exactly like the real app-server (1727/repro/fake-codex-app-server.diff). Run from plugins/provider-codex: pnpm exec vitest run src/bridge/bridge.resume-usage-replay.test.ts. The final assertion fails: the replayed usage for Codex turn turn-fx-1 is emitted as bt…-2-turn-fx-1 while its turn/started went out as bt…-1-turn-fx-1 — precisely the pair the server compares. Output (1727/repro-test-output.txt):
RUN v4.1.1 /home/sawyer/projects/bb/.claude/worktrees/wf_242c3e11-a10-33/plugins/provider-codex
❯ bb-plugin-provider-codex src/bridge/bridge.resume-usage-replay.test.ts (1 test | 1 failed) 78ms
× re-scopes the previous turn's replayed usage under a new session prefix, so it no longer matches its stored turn/started 77ms
⎯⎯⎯⎯⎯⎯⎯ Failed Tests 1 ⎯⎯⎯⎯⎯⎯⎯
FAIL bb-plugin-provider-codex src/bridge/bridge.resume-usage-replay.test.ts > re-scopes the previous turn's replayed usage under a new session prefix, so it no longer matches its stored turn/started
AssertionError: expected 'bt95552e70-2-turn-fx-1' to be 'bt95552e70-1-turn-fx-1' // Object.is equality
Expected: "bt95552e70-1-turn-fx-1"
Received: "bt95552e70-2-turn-fx-1"
❯ src/bridge/bridge.resume-usage-replay.test.ts:168:26
166| // drops it ("Dropped orphan thread-state snapshot with no stored
167| // turn/started"). A stable per-thread id mapping would make this pa…
168| expect(replayedTurnId).toBe(storedTurnId);
| ^
169| }, 30_000);
170|
⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯[1/1]⎯
Test Files 1 failed (1)
Tests 1 failed (1)
Start at 08:07:26
Duration 868ms (transform 410ms, setup 0ms, import 696ms, tests 78ms, environment 0ms)
import { mkdtempSync, rmSync } from "node:fs";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { fileURLToPath } from "node:url";
import { afterEach, beforeEach, expect, it, vi } from "vitest";
import { threadEventNotificationSchema } from "@bb/provider-bridge-protocol";
import { createBridgeJsonRpcTestHarness } from "@bb/provider-bridge-protocol/testing";
import { handleLine } from "./bridge.js";
/**
* Repro for get-bb/bb#1727.
*
* `codex app-server` replays the rollout's last-turn token usage on
* `thread/resume`, scoped to that previous turn's Codex turn id (observed live
* with codex-cli 0.147.0). The bridge stamps every turn scope with a
* per-session id prefix (`bt<entropy>-<serial>-`), so the SAME Codex turn is
* emitted under a different bb turn id in the resumed session than the one
* its `turn/started` was stored under. The server therefore sees a
* thread/tokenUsage/updated for a turn with "no stored turn/started" and drops
* it with a warn log ("Dropped orphan thread-state snapshot ...").
*
* This test drives the bridge through two sessions against the fake
* app-server and shows the id mismatch directly.
*/
const THREAD_ID = "thr_1727_resume_usage";
// The fake app-server replays usage on resume for `usage-replay-*` ids.
const PROVIDER_THREAD_ID = "usage-replay-1727";
const BRIDGE_MINTED_ID_PATTERN = /^bt[0-9a-f]{8}-\d+-/;
const fakeAppServerPath = fileURLToPath(
new URL("./fake-codex-app-server.mjs", import.meta.url),
);
const sessionOptions = {
permissionMode: "full",
permissionScope: "full",
approvalReviewer: null,
permissionEscalation: null,
} as const;
let harness: ReturnType<typeof createBridgeJsonRpcTestHarness>;
let workspaceDir: string;
beforeEach(() => {
workspaceDir = mkdtempSync(join(tmpdir(), "bb-codex-1727-ws-"));
vi.stubEnv("BB_CODEX_BRIDGE_APP_SERVER_COMMAND", process.execPath);
vi.stubEnv(
"BB_CODEX_BRIDGE_APP_SERVER_ARGS",
JSON.stringify([fakeAppServerPath]),
);
harness = createBridgeJsonRpcTestHarness(handleLine);
});
afterEach(async () => {
const cleanupId = 993_001;
harness.sendRequest(cleanupId, "thread/stop", {
threadId: THREAD_ID,
providerThreadId: PROVIDER_THREAD_ID,
intent: "release",
activeTurnId: null,
});
await harness.waitForResponse(cleanupId).catch(() => undefined);
harness.restore();
vi.unstubAllEnvs();
rmSync(workspaceDir, { recursive: true, force: true });
});
function threadEventsOfType(type: string) {
return harness.messages.flatMap((message) => {
if (message.method !== "thread/event") return [];
const parsed = threadEventNotificationSchema.safeParse(message.params);
if (!parsed.success) return [];
return parsed.data.event.type === type ? [parsed.data.event] : [];
});
}
function turnIdOf(event: { scope: { kind: string; turnId?: string } }) {
if (event.scope.kind !== "turn" || event.scope.turnId === undefined) {
throw new Error(`expected a turn-scoped event, got ${event.scope.kind}`);
}
return event.scope.turnId;
}
async function waitFor(predicate: () => boolean, label: string) {
const deadline = Date.now() + 10_000;
while (!predicate()) {
if (Date.now() > deadline) throw new Error(`timed out waiting for ${label}`);
await new Promise((resolve) => setTimeout(resolve, 20));
}
}
it("re-scopes the previous turn's replayed usage under a new session prefix, so it no longer matches its stored turn/started", async () => {
// Session 1: resume + run one turn. The fake's first turn is `turn-fx-1`,
// the same Codex turn id it replays usage for on the next resume — exactly
// the live shape (last completed turn == replayed usage turn).
harness.sendRequest(1, "thread/resume", {
threadId: THREAD_ID,
providerThreadId: PROVIDER_THREAD_ID,
cwd: workspaceDir,
instructionMode: "append",
options: { ...sessionOptions },
});
const resumed1 = await harness.waitForResponse(1);
expect(resumed1.error).toBeUndefined();
harness.sendRequest(2, "turn/start", {
threadId: THREAD_ID,
providerThreadId: PROVIDER_THREAD_ID,
clientRequestId: "creq_a2b3c4d5e6",
input: [{ type: "text", text: "Reply only with ok.", mentions: [] }],
options: { ...sessionOptions },
});
await harness.waitForResponse(2);
await waitFor(
() => threadEventsOfType("turn/completed").length === 1,
"session 1 turn/completed",
);
const [turnStarted1] = threadEventsOfType("turn/started");
expect(turnStarted1).toBeDefined();
const storedTurnId = turnIdOf(turnStarted1!); // what the server persisted
expect(storedTurnId).toMatch(BRIDGE_MINTED_ID_PATTERN);
expect(storedTurnId.replace(BRIDGE_MINTED_ID_PATTERN, "")).toBe("turn-fx-1");
// Release the session (idle reap / archive / daemon restart all end here).
harness.sendRequest(3, "thread/stop", {
threadId: THREAD_ID,
providerThreadId: PROVIDER_THREAD_ID,
intent: "release",
activeTurnId: null,
});
await harness.waitForResponse(3);
const usageCountBeforeResume = threadEventsOfType(
"thread/tokenUsage/updated",
).length;
// Session 2: resume again. Codex replays the last turn's usage BEFORE any
// new turn/started exists.
harness.sendRequest(4, "thread/resume", {
threadId: THREAD_ID,
providerThreadId: PROVIDER_THREAD_ID,
cwd: workspaceDir,
instructionMode: "append",
options: { ...sessionOptions },
});
const resumed2 = await harness.waitForResponse(4);
expect(resumed2.error).toBeUndefined();
await waitFor(
() =>
threadEventsOfType("thread/tokenUsage/updated").length >
usageCountBeforeResume,
"replayed usage after resume",
);
const replayedUsage = threadEventsOfType("thread/tokenUsage/updated").at(-1)!;
const replayedTurnId = turnIdOf(replayedUsage);
// Same Codex turn ...
expect(replayedTurnId.replace(BRIDGE_MINTED_ID_PATTERN, "")).toBe(
storedTurnId.replace(BRIDGE_MINTED_ID_PATTERN, ""),
);
// ... but a different bb turn id: the server has a turn/started stored
// only for `storedTurnId`, so `resolveDaemonTurnStartDisposition` in
// packages/db/src/data/events.ts classifies this snapshot as an orphan and
// drops it ("Dropped orphan thread-state snapshot with no stored
// turn/started"). A stable per-thread id mapping would make this pass.
expect(replayedTurnId).toBe(storedTurnId);
}, 30_000);
diff --git a/plugins/provider-codex/src/bridge/fake-codex-app-server.mjs b/plugins/provider-codex/src/bridge/fake-codex-app-server.mjs
index 37a623825..35395ecfa 100644
--- a/plugins/provider-codex/src/bridge/fake-codex-app-server.mjs
+++ b/plugins/provider-codex/src/bridge/fake-codex-app-server.mjs
@@ -193,6 +193,33 @@ async function handleRequest(message) {
);
return;
}
+ // Mirror the real app-server (codex-cli 0.147.0, observed live for
+ // #1727): thread/resume replays the rollout's last-turn token usage,
+ // scoped to that PREVIOUS turn's id, before any new turn is started.
+ // Opt-in via a `usage-replay-` provider-thread-id prefix.
+ if (String(params.threadId).startsWith("usage-replay-")) {
+ notify("thread/tokenUsage/updated", {
+ threadId: params.threadId,
+ turnId: "turn-fx-1",
+ tokenUsage: {
+ total: {
+ totalTokens: 39970,
+ inputTokens: 39960,
+ cachedInputTokens: 0,
+ outputTokens: 10,
+ reasoningOutputTokens: 0,
+ },
+ last: {
+ totalTokens: 19993,
+ inputTokens: 19988,
+ cachedInputTokens: 0,
+ outputTokens: 5,
+ reasoningOutputTokens: 0,
+ },
+ modelContextWindow: 258400,
+ },
+ });
+ }
respond(id, { thread: { id: params.threadId } });
return;
}
Root cause
- Codex replays last-turn usage on resume/fork. Verified with the raw probe (section A):
thread/resumeandthread/forkeach emit onethread/tokenUsage/updatedcarrying the rollout's last turn id, before any turn is started. The bridge translates it 1:1 intothread/tokenUsage/updated+thread/contextWindowUsage/updated, both turn-scoped: event-translation.ts#L975-L1016. The bridge sendsthread/resume/thread/forkat bridge.ts#L1135-L1160. - The bridge re-mints turn ids per session.
bridgeIdEntropyPrefixis a per-process nonce (bridge.ts#L369), each session getsidPrefix = entropy + serial + "-"(#L1045-L1055), andremapScope/remapEventstamp it on every turn scope (#L491-L513). This is the protocol's rule ("turn ids embed per-bridge-instance entropy … so ids never collide across process restarts or session resumes", provider-bridge-protocol.md#L99-L109), so it is not itself a bug. Its consequence: the replayed usage for Codex turn X is emitted as<newPrefix>X, but bb storedturn/startedfor<oldPrefix>X(resume) or never stored it at all (fork). The protocol also says a bridge "must never reference a turn id bb has not seen" (#L139-L141); the codex bridge does here. - The server drops it by design.
resolveDaemonTurnStartDispositionreturnsskip-orphan-snapshotfor the two usage types (andprovider/unhandled) when noturn/startedexists for(threadId, turnId), instead of throwingMissingStoredTurnStartedErrorand rolling back the batch: packages/db/src/data/events.ts#L381-L430. The comment there already describes the fork case; the route logs each skip at warn level: apps/server/src/internal/events.ts#L941-L951. Tested in events.test.ts#L437. There is no buffering, and none is needed: the snapshot is not for the upcoming turn.
Why the symptom follows. Resume: same Codex turn, different bb id → orphan → warn ×2 (tokenUsage + contextWindowUsage), payload identical to what is stored → no data effect. Fork: parent's turn id → orphan → warn ×2, and the parent's context-window usage, which the fork genuinely inherits, is discarded until the fork's first turn reports its own.
Deeper point. The domain scope policy already anticipates this: thread/contextWindowUsage/updated is thread-or-turn ("providers can report it before, during, or after a turn") while thread/tokenUsage/updated is turn-only — thread-event-scope.ts#L122-L127. The ACP bridge already emits thread-scoped context usage when no turn is open (acp event-translation.ts#L806-L813); the codex bridge does not make that distinction. Also, the warn line does not include the turn id, which is why the issue could not tell which turn was being dropped.
Proposed fix (first principles)
Fix in the Codex plugin (provider translation is the plugin's job; the server rule is a correct safety net and should stay). In toCanonicalEvents (bridge.ts#L620-L656) track the Codex turn ids this session has emitted turn/started for; when a thread/tokenUsage/updated or thread/contextWindowUsage/updated arrives for any other turn (only replays on resume/fork can produce that), re-scope the context-window usage to {kind:"thread"} and drop the token usage (turn-only by policy; on resume it duplicates the stored snapshot, on fork total is the parent's cumulative count anyway). Prototype diff: 1727/repro/prototype-fix-bridge.diff (applied by apply-prototype-fix.py); a variant of the repro test that encodes the fixed behavior passes (bridge.resume-usage-replay.fixed.test.ts) and the full bb-plugin-provider-codex suite stays green with it (165 passed; only the intentionally failing repro test fails — 1727/prototype-suite-output.txt).
diff --git a/plugins/provider-codex/src/bridge/bridge.ts b/plugins/provider-codex/src/bridge/bridge.ts
index 043249502..82a216411 100644
--- a/plugins/provider-codex/src/bridge/bridge.ts
+++ b/plugins/provider-codex/src/bridge/bridge.ts
@@ -349,6 +349,13 @@ interface CodexBridgeSession {
openedItemIds: Set<string>;
/** Codex-id space; open turns settle as failed if the child dies. */
openCodexTurnIds: Set<string>;
+ /**
+ * Codex-id space; every turn this session has emitted turn/started for.
+ * Thread-state snapshots for any other turn are replays (codex re-emits the
+ * rollout's last-turn usage on thread/resume and thread/fork) and must not
+ * be scoped to a bridge turn id bb has never seen (#1727).
+ */
+ startedCodexTurnIds: Set<string>;
identityAnnounced: boolean;
/**
* Events translated before the session's identity is known (codex can emit
@@ -625,6 +632,23 @@ function toCanonicalEvents(
if (event.type === "turn/started" && event.scope.kind === "turn") {
session.openCodexTurnIds.add(event.scope.turnId);
+ session.startedCodexTurnIds.add(event.scope.turnId);
+ }
+ // Replayed thread-state snapshot (thread/resume, thread/fork): the turn it
+ // names was never started in this session, so its bridge-minted turn id
+ // would be unknown to bb. Context-window usage is session state and may be
+ // thread-scoped; token usage is turn-only and, on resume, duplicates the
+ // snapshot bb already persisted for that turn, so drop it.
+ if (
+ (event.type === "thread/tokenUsage/updated" ||
+ event.type === "thread/contextWindowUsage/updated") &&
+ event.scope.kind === "turn" &&
+ !session.startedCodexTurnIds.has(event.scope.turnId)
+ ) {
+ if (event.type === "thread/contextWindowUsage/updated") {
+ out.push(remapEvent(session, { ...event, scope: { kind: "thread" } }));
+ }
+ return out;
}
if (event.type === "turn/completed" && event.scope.kind === "turn") {
session.openCodexTurnIds.delete(event.scope.turnId);
@@ -1066,6 +1090,7 @@ async function constructThreadSession(
),
openedItemIds: new Set(),
openCodexTurnIds: new Set(),
+ startedCodexTurnIds: new Set(),
identityAnnounced: false,
pendingPreIdentityEvents: [],
openWorkReported: false,
Before landing: bound startedCodexTurnIds like the item-id sets on origin/main (MAX_TRACKED_ITEM_IDS_PER_SESSION), extend the fake app-server so a bridge test covers both resume and fork replay, and confirm in the app that a thread-scoped context usage on a fresh fork renders (the consumer extractThreadContextWindowUsage ignores scope, so it should). Optionally, server side: log the dropped snapshot's scope.turnId and lower the level to info/debug, since the fork replay is expected traffic. What could go wrong: nothing user-visible — this only touches events the server discards today, plus it stores one extra thread-scoped context snapshot per resume/fork (pruned by the existing age-prunable rule). No wire shape changes, so no HOST_DAEMON_PROTOCOL_VERSION bump. Do not "fix" it by making the codex prefix stable across sessions or by buffering server-side: the former contradicts the protocol's collision rule, the latter re-creates the batch-wedging fork failure the drop was added for.
PR review
No open PRs are linked to this issue.
Related issues
- #1640 — provider bridge protocol; introduced the per-session id prefix that turns the resume replay into an orphan (issue was filed from its final validation).
- #1224 — the cross-resume id collision that motivated per-instance entropy in ids.
- #85 — introduced the orphan-snapshot drop for native forks.
- #1320 — bridge-minting rule ("ids that reach bb's persistence are always minted by bb-authored bridge code").
Appendix
Artifacts
- codex-app-server-probe.log — raw app-server probe (full).
- server.log, host-daemon.log — dev instance logs covering both live runs.
- instrumentation.diff — server warn-log instrumentation used for the second run.
- 1727/repro/ — probe script, repro test, fake app-server diff, prototype fix + fixed-behavior test, this report's generator.
Commands run (abridged)
gh issue view 1727 --comments --json title,body,comments,labels
pnpm install --frozen-lockfile --prefer-offline
pnpm exec turbo run build
node /tmp/bb-reports/issues/1727/repro/codex-app-server-probe.mjs /tmp/bb-1727-probe/scratch
git checkout 16ceb3a54 && pnpm exec turbo run build
scripts/bb-dev-app current
curl -s -X POST http://localhost:20350/api/v1/projects -H 'content-type: application/json' -d '{"name":"qa","source":{"type":"local_path","path":"/tmp/bb-1727-probe/scratch","hostId":"host_675q2rjmvs"}}'
CLI="node packages/scripts/dist/commands/run-cli.js"; export BB_SERVER_URL=http://localhost:20350
$CLI thread spawn --project proj_9u4kg498pm --provider codex --permission-mode accept-edits --title "1727 repro" --prompt "Reply only with ok." --json
$CLI thread archive thr_gfmnau443m; $CLI thread unarchive thr_gfmnau443m
$CLI thread tell thr_gfmnau443m "Reply only with ok."; $CLI thread wait thr_gfmnau443m
grep orphan <data dir>/logs/server.1.log
# apply instrumentation.diff, scripts/bb-dev-app current (restart => session release => resume)
$CLI thread tell thr_gfmnau443m "Reply only with ok."; $CLI thread wait thr_gfmnau443m
$CLI thread fork thr_gfmnau443m --workspace reuse --title "1727 fork" --prompt "Reply only with ok." --json; $CLI thread wait thr_3xey7gdhwn
sqlite3 <data dir>/bb.db "select sequence,type,turn_id,data from events where thread_id in ('thr_gfmnau443m','thr_3xey7gdhwn') ..."
cd plugins/provider-codex && pnpm exec vitest run src/bridge/bridge.resume-usage-replay.test.ts # fails (repro)
python3 /tmp/bb-reports/issues/1727/repro/apply-prototype-fix.py plugins/provider-codex/src/bridge/bridge.ts
pnpm exec turbo run typecheck --filter=bb-plugin-provider-codex; cd plugins/provider-codex && pnpm exec vitest run # 165 pass, repro test fails as designed
git checkout -- plugins/provider-codex/src/bridge/bridge.ts
pnpm dev:stop