Sign up
View stargazersSign up

[Bug]: A user message can become a later run than an agent message sent after it#24335

opened4d agobyOonly21mil

Before submitting

  • I searched existing issues and did not find a duplicate.
  • I included enough detail to reproduce or investigate the problem.

Area

apps/server

Steps to reproduce

The replay fixture queued_cancelled_while_active sends a user message, then an agent-queued message for the same thread, then cancels run 2. It expects the user message to be run 1 and the agent message to be run 2. The suite runs it on :memory:. These steps run it on a file database built by layerFromPath, the way the server opens its database.

  1. Check out main and run vp i.
  2. From the repo root, apply this patch with git apply. It replaces the default database layer in apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts with a file database:
diff
1diff --git a/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts b/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
2index 0342a3ccc9..b83702246c 100644
3--- a/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
4+++ b/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
5@@ -1,3 +1,6 @@
6+import * as NodeFs from "node:fs";
7+import * as NodeOs from "node:os";
8+import * as NodePath from "node:path";
9 import * as OtelEnvironment from "@t3tools/shared/otelEnvironment";
10 import { DEFAULT_SIGNAL_EXPORT } from "@t3tools/shared/observability";
11 import * as NodeServices from "@effect/platform-node/NodeServices";
12@@ -289,7 +292,16 @@ export function layerWithRegistry<Error>(
13 : RuntimePolicy.layerWithOverride(scenario.runtimePolicyOverride).pipe(
14 Layer.provide(RuntimePolicy.layer),
15 );
16- const layerDatabase = options.databaseLayer ?? SqlitePersistence.layerMemory;
17+ const layerDatabase =
18+ options.databaseLayer ??
19+ Layer.unwrap(
20+ Effect.sync(() => {
21+ const dir = NodeFs.mkdtempSync(NodePath.join(NodeOs.tmpdir(), "order-repro-"));
22+ return SqlitePersistence.layerFromPath(NodePath.join(dir, "state.sqlite")).pipe(
23+ Layer.provide(NodeServices.layer),
24+ );
25+ }),
26+ );
27 // One queue shared by the adapters, the orchestrator, and the worker, like
28 // runtimeLayer.ts; layer memoization keeps it a single instance.
29 const layerContinuationRequests =
  1. In apps/server, run vp test run src/orchestration-v2/testkit/CodexReplayFixtures.integration.test.ts -t queued_cancelled_while_active.

Expected behavior

  • The user message, sent first, becomes run 1. The agent message becomes run 2, and the fixture cancels it. The test passes, as it does on :memory:.

Actual behavior

  • With the file database, the test failed in 8 of 8 trials. In 5 trials the cancel arrived before the user's run existed, and the test failed in 0.2-0.4 s with Run ...:ordinal:2 is not queued. In the other 3 it cancelled the user's run, and the test timed out after 120 s. With :memory:, the test passed in 8 of 8 trials. How the failures split between the two kinds varies from run to run.
  • The steps above show the failure but not which message got which run. A projection dump added on top of the patch showed it: in a separate 8 + 8 trials, the agent message became run 1 and the user message run 2 in 8 of 8 file-database trials, and the user message was run 1 in 8 of 8 :memory: trials.
  • Cause: dispatchWithReceipt in Orchestrator.ts runs appOwnedSubagentParentThreadId for a message.dispatch from the user or from MCP before it takes the thread lock. That calls projectionStore.getThread, which runs under NodeSqliteClient.readOnly. layerFromPath sets readerWorker: true, so on a file database the read goes to the reader worker and yields. A message that skips that read, such as an agent-queued one, takes the thread lock first. On :memory: there is no reader worker, so the read runs on the writer without yielding and the order holds. A counter on the reader route showed reader reads on every file-database trial and none on :memory:.
  • This looks like the ordering change mentioned in #19211 and #19226. The worker in #19211 made the :memory: read async too, which exposed a race that file databases already have.
  • I have not worked out a fix. The lookup decides whether to take the parent thread's lock before the child's, so moving it inside the child lock would change the lock order.
  • I have not measured how often this happens in a real install. It needs a user or MCP message and an agent message for the same thread within one reader round trip.

Impact

Minor bug or occasional failure

Version or commit

main @ 6c21798485

Environment

Linux (Fedora 44), Node 24.22.1

Logs or stack traces

shell
1file database (layerFromPath), 8 trials: failed 8/8 (5 "Run ...:ordinal:2 is not queued." in 0.2-0.4 s, 3 timeouts at 120 s)
2:memory:, 8 trials: passed 8/8
3traced pass, 8 + 8 trials: run 1 = agent message 8/8 on file DB, user message 8/8 on :memory:

Screenshots, recordings, or supporting files

No response

Workaround

None.

Repro and this text by Claude Opus 5.5 in T3 Code Nightly.

🤖 Generated with Claude Opus 5.5 in T3 Code Nightly