[Bug]: A queued message gets one start attempt per run end, and a newer send that finds the thread idle starts first (queued runs waited up to 25 min) #33838

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

When a run ends, handleRunUpdate calls startNextQueuedRun once. If a run is active by the time it has read the projection, it returns, and nothing tries again until the next run ends. A message.dispatch that finds no active run starts its own run without looking at the queue, because shouldQueue is true only behind an active run. On a busy thread where the release read is slow (#29468), newer sends keep arriving in that window, and older queued messages wait through several run ends.

1. Use a thread that gets a message every one to three minutes from other threads (t3_thread_send, mode auto), plus delegated-task completions.
2. Send a message while a run is active, so it queues.
3. When that run ends, send another message during the gap before the queued run starts.
4. The new message starts a run at once. The queued run stays queued until the new run ends, and can lose again the same way.

Observed on one thread on Nov 10, 2026 (times in UTC). It is a Claude coordinator thread with 64,556 turn items and 6,476 runs. Run numbers below are the N in run:thread:<thread>:ordinal:N.

• Run 6736 (a delegated completion) was queued at 10:22:02.995Z. Three times after that, a run ended, the thread sat with no active run and 6736 still queued, and a newer send then started first:
  • Run 6735 ended 10:35:38.658Z. 101 s later run 6737 was requested (10:37:19.183Z) and it started at 10:37:41.725Z.
  • Run 6737 ended 10:41:08.327Z. 39 s later run 6742 was requested (10:41:47.822Z) and it started at 10:41:49.686Z.
  • Run 6742 ended 10:44:35.110Z. 26 s later run 6743 was requested (10:45:01.612Z) and it started at 10:45:27.650Z.
  • Run 6736 started at 10:47:35.804Z, 1,533 s after it was queued.
• Run 6755 (a send from another thread) was queued at 10:57:48.388Z and started at 11:22:30.564Z, 1,482 s later. Twice in that time the thread had no active run, had runs queued, and a newer send started instead:
  • From 11:10:49.507Z, with 5 runs queued, until run 6768 (requested 11:12:06.010Z) started at 11:12:42.836Z.
  • From 11:16:44.967Z, with 7 runs queued, until run 6772 (requested 11:18:16.322Z) started at 11:18:59.567Z.
• From 10:22Z to 11:22Z, 12 queued runs waited 639 to 1,533 s before starting, and 6 newer messages (5 sends, 1 delegated completion) started at once while older runs were queued. At 11:21Z, 6 runs were still queued.

The release runs late because it reads the whole thread first. One Orchestrator.startNextQueuedRun on this thread took 72,540 ms (started 11:14:47Z), and about 72.2 s of that was ProjectionStore.readCanonicalProjection. From 11:09Z to 11:23Z the thread sat with no active run for 113 to 167 s after each run ended, with runs queued the whole time.

Expected behavior

When a run ends and runs are queued, the oldest queued run starts next, even if a newer send arrives while the release is still reading. If the release finds a run active, it should try again when that run ends. A send that finds the thread idle with a non-empty queue should not start ahead of the queue.

Actual behavior

The release is one attempt per run end. A send that lands before the release has started a run starts its own run and goes first. On this thread, queued messages waited up to 25 minutes while newer ones ran, and the UI showed the thread as finished with 7 messages queued under it.

Impact

Major degradation or frequent failure

Version or commit

0.1.9-nightly.20261110.4452 (8226715). The same logic is on main at d1aeed2, where the line numbers below were read:

• apps/server/src/orchestration-v2/Orchestrator.ts: handleRunUpdate L14243-14290 calls startNextQueuedRun once per terminal run update. startNextQueuedRun L1878-1895 reads the projection at L1888 and returns when projection.runs.some(isActiveRun). In dispatchMessage, shouldQueue (L6348) is true only when there is a run to queue behind. Run updates for all threads go through one Stream.runForEach(handleRunUpdate) (L14328), so a slow release on one thread also delays releases on the others.
• apps/server/src/orchestration-v2/ThreadManagementService.ts: sendToThread L846-851 gives an MCP send start_immediately when the thread has no steerable run (queue_after_active for mode queue, which also starts at once when no run is active).
• apps/server/src/orchestration-v2/CommandPolicy.ts: resolveDeliveryIntent L144-152 returns start_immediately when no run is active, for sends that carry a delivery intent.
• apps/server/src/orchestration-v2/QueuedRunOrder.ts: queuedRunsInDeliveryOrder L12-25 puts delegated completions first.

Environment

macOS 15.8.1, arm64, T3 Code (Nightly) desktop with its bundled server. Claude provider. statev2.sqlite is 30.1 GB. The host was heavily loaded at the time (about 99% CPU).

Logs or stack traces

# server.trace.ndjson, consecutive run-update handlers (start time, span, duration)
11:13:22Z Orchestrator.handleRunUpdate         84170 ms
11:14:47Z Orchestrator.startNextQueuedRun      72540 ms   (the release on the affected thread)
            ProjectionStore.readCanonicalProjection  about 72.2 s
              SELECT payload_json FROM orchestration_v2_projection_turn_items WHERE thread_id = ?   about 35.3 s
              message-to-ordinal pass over the same table                                         about 15.6 s
              SELECT payload_json FROM orchestration_v2_projection_nodes ...                      about 12.6 s
11:15:59Z Orchestrator.startNextQueuedRun       1077 ms

# orchestration_v2_projection_runs for the affected thread (requested_at -> startedAt)
run 6736  10:22:02.995Z -> 10:47:35.804Z  (queued)
run 6737  10:37:19.183Z -> 10:37:41.725Z  (started first)
run 6742  10:41:47.822Z -> 10:41:49.686Z  (started first)
run 6743  10:45:01.612Z -> 10:45:27.650Z  (started first)
run 6755  10:57:48.388Z -> 11:22:30.564Z  (queued)
run 6768  11:12:06.010Z -> 11:12:42.836Z  (started first, 5 queued)
run 6772  11:18:16.322Z -> 11:18:59.567Z  (started first, 7 queued)

Workaround

Promoting queued messages to steer one at a time ("Send now"), but on this thread each promote took 20-61 s (#29468) and they ran one after another. Moving the work to a new, shorter thread shortens the window.

Related: #29468 (the slow whole-thread read, which makes the window wide, with PR #29521) and #26987 (a busy orchestrator's queue grows). Neither covers the single release attempt or an idle-start going ahead of a non-empty queue.

Investigated with Claude Code from T3's own server.trace.ndjson and a read-only query of statev2.sqlite. The run rows are still in the database if more detail helps. The trace files from that hour have rotated out, so the span figures above are what was recorded at the time.