Skip to content

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

Open

Description

@only21mil

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 --git a/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts b/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
index 0342a3ccc9..b83702246c 100644
--- a/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
+++ b/apps/server/src/orchestration-v2/testkit/ProviderReplayHarness.ts
@@ -1,3 +1,6 @@
+import * as NodeFs from "node:fs";
+import * as NodeOs from "node:os";
+import * as NodePath from "node:path";
 import * as OtelEnvironment from "@t3tools/shared/otelEnvironment";
 import { DEFAULT_SIGNAL_EXPORT } from "@t3tools/shared/observability";
 import * as NodeServices from "@effect/platform-node/NodeServices";
@@ -289,7 +292,16 @@ export function layerWithRegistry<Error>(
       : RuntimePolicy.layerWithOverride(scenario.runtimePolicyOverride).pipe(
           Layer.provide(RuntimePolicy.layer),
         );
-  const layerDatabase = options.databaseLayer ?? SqlitePersistence.layerMemory;
+  const layerDatabase =
+    options.databaseLayer ??
+    Layer.unwrap(
+      Effect.sync(() => {
+        const dir = NodeFs.mkdtempSync(NodePath.join(NodeOs.tmpdir(), "order-repro-"));
+        return SqlitePersistence.layerFromPath(NodePath.join(dir, "state.sqlite")).pipe(
+          Layer.provide(NodeServices.layer),
+        );
+      }),
+    );
   // One queue shared by the adapters, the orchestrator, and the worker, like
   // runtimeLayer.ts; layer memoization keeps it a single instance.
   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 fix(server): slow SQLite work no longer forces clients to reconnect #19211 and fix(server): thread list reads no longer freeze the server on large databases #19226. The worker in fix(server): slow SQLite work no longer forces clients to reconnect #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 @ 6c21798

Environment

Linux (Fedora 44), Node 24.22.1

Logs or stack traces

file 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)
:memory:, 8 trials:                      passed 8/8
traced 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

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions