Skip to content

ui-server: a full native journal observation runs after every tool result and delays the next request (230–860 ms per call) #2834

Closed

Description

@schlessera

Context

Every tool result in a hosted turn triggers a full native journal observation, and the turn's next provider request does not go out until it finishes. A tool that costs a few milliseconds in the worker therefore costs 0.3–0.9 s per call. Turn begin and finish each pay one more observation.

Measured on the native hosted fixture (UID 1000, Btrfs loop store, 2,000 notes, offline fake Anthropic model), pi governed turns with 20 calls of each tool. Median / p95 ms per call:

tool round trip (model → model) tool time in worker per-call observation tool end → next request
read_file 298 / 329 18.7 232 209
write_file 373 / 413 18.8 295 279
edit_file 444 / 537 18.8 333 326
bash (cat, echo >) 363 / 457 2.9 282 284
brain_read_base 348 / 434 0.9 231 247
brain_search 516 / 604 93.2 303 312
query_activity / inbox_list 400–425 1.2–3.1 232 274–308

That cell ran at host load average ~2. At load 9–10 (same fixture, later cells) the observation took 520–860 ms and round trips 420–1,140 ms. Across every cell and tool, "tool end → next request" tracks the observation time; relay legs are 1–2 ms. Each observation is one Btrfs snapshot, send --no-data diff, delete and sync, about six identity inspections, and one journal SQLite write.

Turn begin and finish (median / p95 ms, no policy, UID 1000):

Claude pi
journal begin, of which observation 227 / 548 (201) 239 / 379 (209)
journal finish, of which observation 296 / 574 (275) 249 / 321 (229)

At UID 0 both are about twice as long.

Where it happens, verified on af6300478:

  • Every tool result (void host.journal?.observe(), packages/ui-server/src/ws/bridge.ts:170) calls (observe(): Promise<void>, packages/ui-server/src/brain/turn-journal.ts:365), which runs the whole observation (async function observe(, line 202), serialized with every other journal operation.
  • Turn begin (begin(turnId: string, line 323) and finish (finish(turnId: string), line 399) each run one more (await observe();, lines 328 and 395).
  • The native capture behind it (observe(, packages/ui-server/src/brain/native-journal-capture.ts:56) checkpoints and diffs the whole brain subvolume.
  • Host apply waits for any observation in flight first (await host.journal?.idle();, packages/ui-server/src/ws/bridge.ts:621): p95 1.8 s in one cell.
  • The scope monitor also observes when a limit is reached (void options.journal.observe(), packages/ui-server/src/brain/turn-scope.ts:104); the 15 s periodic timer (scopeTimer = setInterval, turn-journal.ts:341) covers long tools.

The journal SQLite commit inside each observation was 14–50 ms per write at the measured commit (69151ca). Since then #2812 removed the per-write WAL checkpoint, and #2814 moves the remaining commit off the event loop. This issue is about how often the native observation runs, how long it takes, and whether the next request waits for it.

Scope

Cut the observation cost on the tool path while keeping the journal complete: every change a turn makes is still captured before the turn's terminal, and scope limits are still enforced. Target: on the native fixture at the same load, a read-only tool call (read_file, brain_read_base, brain_search, query_activity, inbox_list) adds under 50 ms median over its in-worker time, and a write-capable call under 150 ms. Journal begin plus finish together stay under 300 ms median. Implement the approved proven-write-capability schedule below; existing design inputs remain subordinate to that ruling.

Out of scope

Acceptance criteria

  • Actual read-only execution paths skip unnecessary per-result observations; write-capable, bash and unknown/custom paths retain them, proven by tool-class tests and a mutation that incorrectly marks a writer read-only.
  • Terminal and periodic observations remain; asynchronous/background writes and writes between tool calls are captured with unchanged scope detection/stop bounds. When those bounds require an observation, it is not skipped. Tests prove this beyond the tool name or declared risk label.
  • Locate the actual next-request serialization point with before/after timing evidence; do not describe the fire-and-forget bridge call as an await without evidence.
  • The per-tool targets above hold on the native fixture for pi, measured as the model-side round trip minus the in-worker tool time, 20 calls per tool, with the host load recorded in the PR.
  • Journal begin plus finish ≤ 300 ms median on the native fixture for Claude and pi at UID 1000.
  • Every write a turn makes is still in its journal at turn end, including writes by a tool whose result produced no observation, proven by a test that fails if a skipped or coalesced observation loses a change.
  • Scope limits (files_changed, turn_bytes) still stop a turn that crosses them, within the same bound as today, proven by the existing scope tests and one that crosses a limit between two tool calls.

Verification

Reproduction: run the native hosted proof for pi at UID 1000 (bun scripts/prove-native-host.ts --backend=pi --app-uid=1000, under the exclusive native fixture lock) with a test whose fixture model answers one turn with 20 calls of each tool listed above, one per request. Record, per call, the model response time, the next request's arrival, the in-worker tool time and the duration of host.journal.observe(). Raw per-call timelines from the measurement run are retained locally by the maintainer.

Then bun run test packages/ui-server packages/ui-backend-pi packages/ui-backend-claude.

Contract impact

None expected.

Related: #2789, #2814 (journal SQLite commits), #2416 (event-loop impact).

Maintainer decision (2026-10-24)

Option A selected: schedule per-tool observations by proven write capability rather than observing indiscriminately after every tool result. Only calls proven read-only in the actual execution path may skip a per-result observation. Bash, unknown/custom capabilities and write-capable tools retain observation; a declared name or risk label alone is not sufficient evidence.

Preserve the terminal observation, long-running-tool periodic coverage, completeness of retained changes and the current scope-limit enforcement bound. Explicitly cover asynchronous/background side effects and concurrent writers; if skipping an observation would delay detection beyond the current bound or lose required versions, retain observation for that case. No coalescing policy, relaxed overshoot, weakened journal capture or changed durability is authorized.

First attribute the actual serialization delaying the next provider request: bridge.emit fire-and-forgets observe, so correlation does not establish a direct await. Apply the write-capability schedule without bypassing any existing admission, scope or publication barrier. Unknown capability fails conservatively to observation.

Document the execution-path classification and completeness/enforcement argument for each supported tool class, including direct worker reads versus host bridge reads. Preserve existing latency targets and measure the selected schedule; if a target cannot be met without relaxing guarantees, report the shortfall instead of weakening them. Update the journal/governed-workers decision record during implementation.

The later #2831/#2840 receipt also locates repeated ~120 MB disposable-index versions in strict-turn observations. #2840 changes the scope counter, not journal capture/retention. This issue still owns observation cost and ordering; no current-main claim is made for that open PR.

2026-10-24 triage at main 77f35ef1ba34e4fab7092ada5362ae799852ea24: Classified the remaining journal observation ordering question as needs: decision. Folded exact options, consequences, recommendations and ruling evidence into the body while preserving the existing technical prompt and measured targets. No option, consistency relaxation, threshold change or new runtime result is approved.

2026-10-24 maintainer ruling: selected A with proven execution-path capability, conservative observation fallback, full terminal/periodic coverage and unchanged scope/durability guarantees. Architecture approval is not an implementation or performance receipt.

2026-10-25 dependency reconciliation at main 541b8d98328a760290ac6dd4a7f065af76153408: #2873 is delivered by merged #2890 (5322d30bc, ancestor of this main): new disposable-index history is metadata-only and non-restorable, preserving authoritative-content retention. Remove its satisfied active edge; legacy retained-object purge is separate #2903, not evidence that #2873 is unfinished. Keep #2872 and #2915 as the remaining performance prerequisites and keep blocked: no writer or begin/finish target success is inferred. The schedule output consumed by #2872 has already shipped in #2882; aggregate #2834 closure must not form a reverse dependency. Preserve the existing readiness, claim, guards and source-specific failed receipts.

Activity

  1. added this to the 0.44.0 milestone on Oct 24, 2026
  2. added
    type: fixSomething is broken and must behave the way it is documented.
    area: ui-serverHono app factory: turn coordinator, auth, session catalog, routes, cron.
    priority: p1Scheduled into the current or next milestone.
    needs: designBlocked on a design drop or a visual answer.
    on Oct 24, 2026
  3. schlessera commented on Oct 24, 2026

    @schlessera
    OwnerAuthor

    Design needed: when the turn journal observes during a turn, and whether the next request waits for it.

    Decided: the journal must capture every change a turn makes before its terminal, and scope limits must stop a turn that crosses them. Today that is done by a full native observation after every tool result, which the next provider request ends up waiting for (230–860 ms per call). Still open: how often to observe and what may run concurrently with an observation. That trade-off is between completeness proofs and latency, and the code cannot settle it alone.

    You are designing a change for brain-kit (Bun/TypeScript monorepo). Do not write code; produce a design.
    
    Read first
    - The issue this prompt is attached to (per-tool measurements, citations, targets).
    - packages/ui-server/src/ws/bridge.ts:170 (observation on every tool_result) and :621 (apply waits for journal idle).
    - packages/ui-server/src/brain/turn-journal.ts:202 (observe), :323 (begin), :365 (public observe), :399 (finish), :341 (15 s periodic timer).
    - packages/ui-server/src/brain/native-journal-capture.ts:56 (native checkpoint and diff).
    - packages/ui-server/src/brain/turn-scope.ts:104 (scope-limit observation).
    - Tool risk classes for bridge tools: the change in #2823.
    - #2789 and #2814 (journal SQLite commits; separate from this design), #2416 (event-loop lag).
    - docs/decisions/ records on the turn journal and governed workers (governed-writable-workers.md).
    
    The problem
    On the native fixture a pi `read_file` takes 19 ms in the worker but 298 ms model-to-model, because the tool result starts a Btrfs snapshot + diff + delete and the next request goes out only after it finishes. Read-only tools pay the same as writers.
    
    Design: answer each
    1. Which of these, or a combination:
       A. Observe only after tools that can write (by tool risk class and, for bash, always), and rely on the end-of-turn observation for the rest.
       B. Coalesce: at most one observation in flight, later tool results join it, with a minimum interval; scope limits use the latest completed observation.
       C. Make the observation cheaper: reuse the previous checkpoint as the diff base, or narrow it with a dirty-path signal, so each one costs tens of milliseconds.
    2. Why does the next provider request wait for the observation today, and should it? Name the serialization point, and decide whether provider traffic may proceed while an observation runs.
    3. What completeness proof replaces "observed after every tool": which writes could be missed by each option, and how the end-of-turn observation and the 15 s timer cover them.
    4. How scope limits (`files_changed`, `turn_bytes`) keep their bound under each option.
    5. Whether turn begin and finish can share work: begin's observation of the previous turn's end, and finish's checkpoint.
    
    Requirements to hold
    - Every change a turn makes is in its journal at turn end; revert and the Activity record keep working.
    - Scope limits still stop a turn within their current bound.
    - No new extension seam (docs/extending/README.md).
    - Targets: a read-only tool call adds under 50 ms median over its in-worker time, a write-capable call under 150 ms, and journal begin + finish under 300 ms median.
    
    Deliverable
    A short design note: the chosen option, the completeness argument per tool class, the scope-limit argument, expected per-call cost, and the tests that would fail if a change were lost. A documented no ("observing after every tool is required because …") is an acceptable outcome.
    
  4. schlessera commented on Oct 24, 2026

    @schlessera
    OwnerAuthor

    Evidence from the #2831 investigation, relevant to this issue's cost: in the strict edits phase, each per-tool_result observation also captures a new hashed version of .brain-index/brain.db, because every host apply refreshes the index (#2835). In the stalled strict run the turn journal held 36 versions of a ~120 MB index (plus three .brain-index/.maintenance-<uuid> publication copies of 77–107 MB), and the observation after each edit took about 3 s. #2840 stops those versions inflating the turn_bytes scope counter. It does not change what the journal captures or retains, which still lies within this issue's scope.

  5. added
    needs: decisionBlocked on a maintainer or designer ruling, not on code.
    and removed
    needs: designBlocked on a design drop or a visual answer.
    on Oct 24, 2026
  6. schlessera commented on Oct 24, 2026

    @schlessera
    OwnerAuthor

    2026-10-24 triage at main 77f35ef1ba34e4fab7092ada5362ae799852ea24: Classified the remaining journal observation ordering question as needs: decision. Folded exact options, consequences, recommendations and ruling evidence into the body while preserving the existing technical prompt and measured targets. No option, consistency relaxation, threshold change or new runtime result is approved.

  7. schlessera commented on Oct 24, 2026

    @schlessera
    OwnerAuthor

    Decision (maintainer, 2026-10-24): Option A. Schedule observations by proven tool write capability; proven read-only execution paths may skip per-result observation. Bash, write-capable and unknown/custom cases retain observation. Preserve terminal/periodic capture, asynchronous/background-write completeness and current scope-limit detection/stop bounds; observe whenever skipping cannot meet those guarantees. No overshoot relaxation, coalescing policy or durability weakening is approved. Attribute the real serialization rather than assuming the fire-and-forget bridge call is awaited. The body now records the selected schedule and proof criteria; the decision is resolved.

  8. added
    agent-readyContext and acceptance criteria are complete enough for an agent to take this unattended.
    and removed
    needs: decisionBlocked on a maintainer or designer ruling, not on code.
    on Oct 24, 2026
  9. schlessera commented on Oct 25, 2026

    @schlessera
    OwnerAuthor

    Claim wi-2834-7f3c: working this on branch fix/2834-readonly-observation-044 (from main at b192ca0) under the Option A ruling: proven-execution-path read skips, conservative observation for bash, writers and unknown/custom calls. A draft PR follows with native fixture timings.

  10. self-assigned this
    on Oct 25, 2026
  11. schlessera commented on Oct 25, 2026

    @schlessera
    OwnerAuthor

    Draft PR #2882 implements the Option A schedule (Refs, not Closes): a result skips its observation only when the backend proved, from the call's actual RPCs, a host bridge read or pi's curated read_file in an extension-free worker, no other call is running and no active turn ran an unproven call. Everything else observes as before; begin/finish, the 15 s timer and scope-limit enforcement are unchanged. The serialization point was the observation's hold (it freezes the turn's workers), not the fire-and-forget bridge call.

    Native fixture (pi, governed, UID 1000, load 12–17): proven reads went from 546–607 ms added (held 19–20 of 20) to 72–98 ms (held 0 of 20). Not met: reads < 50 ms at that load (the remainder is pi/relay time outside the journal), writers < 150 ms and begin + finish ≤ 300 ms (the observation itself: #2872; index versions retained after each refresh, needs a ruling: #2873). Further follow-ups: #2874, #2875, #2878.

  12. added
    blockedWaiting on another issue or an upstream dependency. Say which in the body.
    on Oct 25, 2026
  13. schlessera commented on Oct 25, 2026

    @schlessera
    OwnerAuthor

    2026-10-25: #2882 merged as 1c5666e7a (Refs): proven reads no longer wait on an observation (added time 546–607 ms → 72–98 ms median under host load 15–17; the remainder is pi response handling, not the journal). Writers (<150 ms) and journal begin+finish (≤300 ms) stay unmet: they are the observation's own cost (#2872) and the retained index versions in finish (#2873). Both are now blockers and in 0.44.0.

  14. schlessera commented on Oct 25, 2026

    @schlessera
    OwnerAuthor

    2026-10-25 dependency reconciliation at main 541b8d98328a760290ac6dd4a7f065af76153408: #2873 is delivered by merged #2890 (5322d30bc, ancestor of this main): new disposable-index history is metadata-only and non-restorable, preserving authoritative-content retention. Remove its satisfied active edge; legacy retained-object purge is separate #2903, not evidence that #2873 is unfinished. Keep #2872 and #2915 as the remaining performance prerequisites and keep blocked: no writer or begin/finish target success is inferred. The schedule output consumed by #2872 has already shipped in #2882; aggregate #2834 closure must not form a reverse dependency. Preserve the existing readiness, claim, guards and source-specific failed receipts.

  15. removed
    blockedWaiting on another issue or an upstream dependency. Say which in the body.
    on Oct 25, 2026
  16. schlessera commented on Oct 25, 2026

    @schlessera
    OwnerAuthor

    Closing (maintainer, 2026-10-25): accepted as substantially delivered in 0.44.0. Proven reads: the journal adds nothing (546–607 ms → 72–98 ms, remainder is pi response handling; #2882). Write-capable calls ~280–330 → 172–186 ms added and journal begin+finish ~550–630 → 347 ms (best quiet runs; #2931 / #2872, plus #2890 / #2873). The original <150 ms writer and ≤300 ms begin+finish targets remain unmet; attribution and further cuts continue in #2915 (0.45.0).

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

Metadata

Metadata

Assignees

Labels

agent-readyContext and acceptance criteria are complete enough for an agent to take this unattended.area: ui-serverHono app factory: turn coordinator, auth, session catalog, routes, cron.priority: p1Scheduled into the current or next milestone.type: fixSomething is broken and must behave the way it is documented.

Projects

No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions