← reports

#1749 · timelineWindowEventBudget assumes 0.06ms/event; measured 0.479ms/event on a 4-core host

Performance Medium Effort: unknown perf host open on GitHub 2026-08-18 base 16ceb3a540f81c1189efaffb27a39b1d9443abf5 (main)

Verdict: PARTIALLY REPRODUCED · root-cause confidence: high (mechanism) / low (the reporter's exact numbers) · linked open PRs: #1756 (docs only)

TL;DR

Plain-language framing. Every time the app or CLI asks the server for a thread's timeline, the server rebuilds it from the thread's stored events: it reads the newest N event rows out of SQLite, JSON.parses each one, and projects them into rows. That work is synchronous, so while it runs the server's single event loop is blocked for everyone, including the host daemon which waits on the server before each dynamic tool call. To bound that work, PR #882 capped a timeline "window" at timelineWindowEventBudget = 1500 events, justified in a source comment by "~0.06 ms/event, so a cold build stays near 100 ms".

The reporter runs bb on a 4-core VPS and derived ~0.48 ms/event (p50) from the server's own Thread timeline build blocked the event loop log lines, i.e. a full 1500-event window costs ~700 ms there, not 100 ms. This is not a functional bug: nothing is wrong, lost or crashing. It is a calibration problem: the budget is a fixed event count, but the cost per event is dominated by CPU speed and by payload bytes (SQLite read + JSON decode are ~80% of a build), both of which vary a lot between hosts. The env var BB_FF_TIMELINE_WINDOW_EVENT_BUDGET already exists as an escape hatch and is documented in docs/configuration.md.

What I could verify: the mechanism, the code path, the cache-invalidation-per-event claim, and that the build cost scales with available CPU. On this Ryzen 7 workstation the constant is actually conservative (0.024 ms/event, 36 ms for a full 1500-event window at ~0.9 KB/event). Throttled to ~25% of one core the same window takes 124 ms and the "100 ms" premise fails; on the reporter's VPS it is presumably far worse. What I could not verify: the reporter's exact 0.479 ms/event, which comes from a biased sample — the slow-build logger only emits for builds ≥ 150 ms, so per-event cost computed from those lines is conditioned on the build already being slow (see Claims). PR #1756 only adds documentation and copies those numbers into a source comment; it does not change behavior.

Claims vs findings

ClaimStatusEvidence
The constant is calibrated at "~0.06 ms/event", 1500 → "cold build near 100 ms"Verifiedfeature-flags.ts#L31-L37; origin is PR #882 ("Bound timeline windows by event count"), measured on a production bundle against a real DB.
Measured 0.479 ms/event p50 (p90 0.964, max 5.55) on a 4-core/4.9 GiB VPS from 541 slow-build log samplesUnverifiable, and biased upward by constructionI do not have that hardware. The Thread timeline build blocked the event loop line is emitted only when totalDurationMs ≥ 150 (timeline-build-log.ts#L17) and at most once per thread per 30 s. Every sampled build is therefore one that was already slow; builds at 0.06 ms/event (a 1257-event window = 75 ms) never appear. The p50 across such lines is a p50 of the slow tail, not of all builds. The 5.55 ms/event max also almost certainly includes GC pauses or other synchronous work landing inside the timed region.
Per-event cost is hardware dependent (~8x spread)Verified in direction, magnitude unverifiedRepro test: 0.024 ms/event on this workstation; 0.083–0.12 ms/event when the same test is pinned to one core shared with three busy loops (~4x). Cost is CPU-bound and linear in bytes (see table below), so a slow vCPU with steal time can plausibly reach the reported range.
Representative build: 1257 events / 1.48 MB read and decoded to return 96 rows; event-json-decode the dominant stageConsistent with code and my measurementsOn the seeded fixture, event-query + event-json-decode are ~80% of a build; projection ~10–15%. Both dominant stages scale with payload bytes.
Only 2 of 76 threads exceed 1500 events, so the budget "rarely binds"Unverifiable for their DB; mechanism verifiedThe budget floor is OFFSET eventBudget on a descending scan (events.ts#L2471-L2491); when the thread has fewer events it returns undefined and only the segment (user-message) limit of 20 bounds the read. On the seeded 60-thread fixture the budget bound 20 threads; the segment limit bound the rest at ≤ ~900 events.
Cache key includes maxSeq, so every appended event invalidates the entry and an active thread rebuilds continuouslyVerified (cache key) / Partially (rebuild rate)Cache key: verified. "Continuously": overstated — the client paces its trailing refetch to the observed fetch duration (min 50 ms, max 1 s, "caps that duty cycle near 50%") and coalesces events that arrive mid-fetch (realtime-cache-registry.ts#L135-L157, introduced by PR #882), so during a streaming turn rebuilds are sustained but coalesced — roughly one build per (build duration, floored at 50 ms), not one per appended event. timeline-cache.ts#L124-L129; the route computes maxSeq = getLatestThreadSequence(...) per request (data.ts#L321-L361). Delta responses still rebuild the full window first ("Reprojecting the full window first keeps every ... case correct by construction"). This is by design (see comment in timeline-build-log.ts: "a viewed long thread rebuilds back-to-back for the whole turn").
Each build churns 0.5–1.5 MB of transient parsed JSONPlausible / consistentMy full-window builds read 1.3 MiB of stored JSON per build (windowKiB=1302); the parsed object graph is larger. Heap impact itself not measured here.
Lowering to 400 via BB_FF_TIMELINE_WINDOW_EVENT_BUDGET works as an operator workaround (~190 ms cold builds on their host)Verified as a mechanismEnv var wired in config/feature-flags.ts#L27-L32. In the repro, budget 400 cut the window from 1500 to 500 events and the build from 36 ms to 12 ms (contended: 124 ms → 41 ms). Note the window is 500 not 400: a whole finished turn is always returned even when it exceeds the budget (deliberate, timeline.ts#L1219-L1227).
Event-loop stall samples: maxDelay p95 5 s, max 50.6 sUnverifiable; unlikely to be timeline builds aloneA 50 s stall at even 5 ms/event would need a 10k-event window, which the budget forbids. Other synchronous work (GC, SQLite checkpoints, other stall sources) is more likely; the stall monitor attributes work by label and that attribution was not shared.
"The env var should be mentioned somewhere discoverable"Already documenteddocs/configuration.md "Thread Timeline Window" section, the built-in guide template packages/templates/src/templates/bb-guide-customization.md:121 and the bb-cli skill SKILL.md:118 all name BB_FF_TIMELINE_WINDOW_EVENT_BUDGET at base.

Environment

Minimal reproduction

The repro is one vitest file: 1749/repro/timeline-event-budget-cost.repro.test.ts (copy it to apps/server/test/services/threads/). It has two scenarios; the second one carries the assertion. Both print a table via console.log and, because the server's vitest config silences passing-test stdout (silent: "passed-only"), also append it to $REPRO_1749_OUT when set.

  1. Build once: pnpm install --frozen-lockfile --prefer-offline && pnpm exec turbo run build.
  2. Copy the test in and run it on the idle machine: 
    cp /tmp/bb-reports/issues/1749/repro/timeline-event-budget-cost.repro.test.ts apps/server/test/services/threads/
cd apps/server
REPRO_1749_OUT=/tmp/repro-1749.txt pnpm exec vitest run test/services/threads/timeline-event-budget-cost.repro.test.ts
cat /tmp/repro-1749.txt
    Expected (documented premise): ~0.06 ms/event and a full 1500-event window at ~100 ms. Actual on this workstation (repro-output-main.txt) — faster than documented, so the assertion passes here: 
    host: x64 node v24.18.0
threads=60 budget=1500 threadsWhereBudgetBinds=20
ms/event (threads>=200 events, n=44): p50=0.028 p90=0.032 max=0.033  (documented: 0.06)
ms/KiB  (same threads): p50=0.053 p90=0.063

threadEvents  windowEvents  windowKiB  bytes/evt  strategy  respRows  buildMs  ms/evt   query  decode  project
        1512           908        483        545  standard-window       100     23.6   0.026    13.1     8.9      2.8
        2210           876        448        523  standard-window       106     24.8   0.028     8.2    12.8      2.5
        2668           866        511        604  standard-window        93     23.9   0.028     9.8     9.1      3.0
        ...
budget=1500: strategy=standard-window windowEvents=1500 windowKiB=1302 bytes/evt=889 respRows=12 segments=3 build p50=36.4ms max=48.1ms ms/evt=0.024 [query=19.8 decode=22.1 project=5.1]
budget=400:  strategy=standard-window windowEvents=500  windowKiB=434  bytes/evt=889 respRows=4  segments=1 build p50=12.1ms max=15.8ms ms/evt=0.024 [query=5.5 decode=7.7 project=2.1]
  3. Now run the same test with the CPU budget of a small, oversubscribed vCPU: pin vitest to one core and share that core with three busy loops (script 1749/repro/run-contended.sh, usage run-contended.sh <worktree-root> <out-file>; set CORE= to pick the core, LOOPS= for the number of busy loops, default 3). Prerequisites: Linux with taskset (util-linux); the script exits 2 otherwise. This is a simulation of slow hardware, not the reporter's VPS, and the outcome is host-dependent: the assertion (p50 ≤ 100 ms for a 1500-event window) fails only once the throttled per-event cost exceeds 100/1500 ≈ 0.067 ms/event. On a CPU much faster than this Ryzen 7 three loops may not be enough — raise LOOPS. Measured on this box: 124.5 ms (original run), 141.9 ms (independent verifier, same machine), 186.4 ms (re-run for this revision, repro-output-contended-revised.txt) — same failing assertion each time, magnitude varies with whatever else the box is doing. 
    bash /tmp/bb-reports/issues/1749/repro/run-contended.sh "$PWD" /tmp/repro-1749-contended.txt
    Actual (repro-output-contended.txt) — the same code, same data, ~4x the per-event cost, and the documented "cold build near 100 ms" premise fails: 
    × long agentic turns: a full 1500-event window at ~1.2KB/event vs the 100ms target 3007ms
AssertionError: expected 124.5 to be less than or equal to 100

ms/event (threads>=200 events, n=44): p50=0.119 p90=0.146 max=0.167  (documented: 0.06)
ms/KiB  (same threads): p50=0.237 p90=0.285
budget=1500: strategy=standard-window windowEvents=1500 windowKiB=1302 bytes/evt=889 respRows=12 segments=3 build p50=124.5ms max=140.7ms ms/evt=0.083 [query=44.6 decode=73.0 project=22.1]
budget=400:  strategy=standard-window windowEvents=500  windowKiB=434  bytes/evt=889 respRows=4  segments=1 build p50=41.0ms  max=67.5ms  ms/evt=0.082 [query=12.5 decode=22.7 project=1.2]
    The assertion that fails is expect(defaultBudgetP50).toBeLessThanOrEqual(100): the p50 of nine builds of a window that fills the default budget (1500 events, ~1.3 MiB) is 124.5 ms, i.e. the budget no longer delivers what its comment promises once the CPU is slower. Read the ms/evt column: 0.024 idle vs 0.083–0.12 contended for identical input — cost per event is a property of the host, not of the constant.

Notes on the fixture: seedPerfFixture turns are short (8–60 items), so with segmentLimit 20 the segment limit binds at ~900 events before the event budget does; that first scenario is informational (it shows cost per event/KiB across 44 threads). The second scenario builds 6 turns × 500 events at ~0.9 KB/event (command executions with multi-KB output plus agent-message deltas), so the newest 3 whole turns exactly fill the 1500 budget — the shape the issue reports (1257 events, 1.18 KB/event, 96 rows from 20 segments).

Repro test source

/**
 * Repro / measurement for get-bb/bb#1749.
 *
 * `defaultFeatureFlags.timelineWindowEventBudget` (1500) is justified by a
 * "~0.06ms/event" figure and a "cold build near 100ms" target. This test seeds
 * a realistic long-tail fixture (the same generator `pnpm seed:perf` uses),
 * builds the latest page for every thread the way the route does, and prints
 * the measured cost per event so the reader can compare with that figure.
 *
 * The one assertion encodes the *documented* budget: a full 1500-event window
 * must build in <= 100ms at p50 on the machine running the test. It passes on
 * fast hardware and fails on slow hardware, which is precisely the issue.
 */
import { appendFileSync } from "node:fs";
import { describe, expect, it } from "vitest";
import { sql } from "drizzle-orm";
import {
  createConnection,
  createProject,
  createThread,
  getThread,
  insertEvents,
  migrate,
  noopNotifier,
  upsertHost,
} from "@bb/db";
import type { DbConnection } from "@bb/db";
import {
  defaultFeatureFlags,
  encodeClientTurnRequestIdNumber,
  threadScope,
  turnScope,
} from "@bb/domain";
import type { Thread } from "@bb/domain";
import { seedPerfFixture } from "../../../../../packages/scripts/src/lib/seed-perf-fixture.js";
import { buildThreadTimelineWithProfile } from "../../../src/services/threads/timeline.js";
import { DEFAULT_MAX_INLINE_OUTPUT_CHARS } from "../../../src/services/threads/timeline-output-truncation.js";

const EVENT_BUDGET = defaultFeatureFlags.timelineWindowEventBudget;

/** vitest silences passing-test stdout here, so also append to a file when asked. */
function report(text: string): void {
  // eslint-disable-next-line no-console
  console.log(text);
  const out = process.env["REPRO_1749_OUT"];
  if (out) appendFileSync(out, `${text}\n\n`);
}
const DOCUMENTED_MS_PER_EVENT = 0.06;
const DOCUMENTED_COLD_BUILD_TARGET_MS = 100;

interface Sample {
  threadId: string;
  totalEvents: number;
  eventRowCount: number;
  eventDataBytes: number;
  strategy: string;
  responseRows: number;
  ms: number;
  stages: Record<string, number>;
}

function percentile(values: number[], p: number): number {
  const sorted = [...values].sort((a, b) => a - b);
  const idx = Math.min(
    sorted.length - 1,
    Math.floor((p / 100) * sorted.length),
  );
  return sorted[idx] ?? 0;
}

function build(db: DbConnection, threadId: string, budget: number) {
  const thread = getThread(db, threadId);
  if (!thread) throw new Error("missing thread");
  return buildThreadTimelineWithProfile(db, thread, {
    eventBudget: budget,
    includeProviderUnhandledOperations: false,
    includeNestedRows: false,
    maxInlineOutputChars: DEFAULT_MAX_INLINE_OUTPUT_CHARS,
    maxSeq: 0,
    page: { kind: "latest", segmentLimit: 20 },
    planCommand: null,
    summaryOnly: false,
  });
}

describe("#1749 timelineWindowEventBudget calibration", () => {
  it("per-event build cost across the perf fixture (informational; segment limit binds before the event budget)", () => {
    const db = createConnection(":memory:");
    migrate(db);
    const seeded = seedPerfFixture(db, {
      hostId: "host_repro_1749",
      workspacesRootPath: "/tmp/repro-1749",
      projectCount: 2,
      threadCount: 60,
      eventCount: 60_000,
      randomSeed: 1749,
    });
    const totalEventsByThread = new Map<string, number>();
    for (const row of db.all<{ threadId: string; n: number }>(
      sql`select thread_id as threadId, count(*) as n from events group by thread_id`,
    )) {
      totalEventsByThread.set(row.threadId, row.n);
    }

    // Warm SQLite page cache + JIT once, then take the measured pass.
    for (const id of seeded.threadIds) build(db, id, EVENT_BUDGET);

    const samples: Sample[] = [];
    for (const id of seeded.threadIds) {
      const runs: number[] = [];
      let last: ReturnType<typeof build> | null = null;
      for (let i = 0; i < 5; i += 1) {
        last = build(db, id, EVENT_BUDGET);
        runs.push(last.profile.totalDurationMs);
      }
      if (!last) continue;
      const p = last.profile;
      const stages: Record<string, number> = {};
      for (const s of p.stageTimings) stages[s.stage] = s.durationMs;
      samples.push({
        threadId: id,
        totalEvents: totalEventsByThread.get(id) ?? 0,
        eventRowCount: p.eventRowCount,
        eventDataBytes: p.eventDataBytes,
        strategy: p.selectionStrategy,
        responseRows: p.responseRowCount,
        ms: percentile(runs, 50),
        stages,
      });
    }

    samples.sort((a, b) => b.eventRowCount - a.eventRowCount);
    const measured = samples.filter((s) => s.eventRowCount >= 200);
    const perEvent = measured.map((s) => s.ms / s.eventRowCount);
    const perKB = measured.map((s) => s.ms / (s.eventDataBytes / 1024));
    const bound = samples.filter((s) => s.totalEvents > EVENT_BUDGET).length;

    const lines: string[] = [];
    lines.push(`host: ${process.arch} node ${process.version}`);
    lines.push(
      `threads=${samples.length} budget=${EVENT_BUDGET} threadsWhereBudgetBinds=${bound}`,
    );
    lines.push(
      `ms/event (threads>=200 events, n=${perEvent.length}): p50=${percentile(perEvent, 50).toFixed(3)} p90=${percentile(perEvent, 90).toFixed(3)} max=${Math.max(...perEvent).toFixed(3)}  (documented: ${DOCUMENTED_MS_PER_EVENT})`,
    );
    lines.push(
      `ms/KiB  (same threads): p50=${percentile(perKB, 50).toFixed(3)} p90=${percentile(perKB, 90).toFixed(3)}`,
    );
    lines.push("");
    lines.push(
      "threadEvents  windowEvents  windowKiB  bytes/evt  strategy  respRows  buildMs  ms/evt   query  decode  project",
    );
    for (const s of samples.slice(0, 25)) {
      lines.push(
        `${String(s.totalEvents).padStart(12)}  ${String(s.eventRowCount).padStart(12)}  ${(s.eventDataBytes / 1024).toFixed(0).padStart(9)}  ${(s.eventDataBytes / Math.max(1, s.eventRowCount)).toFixed(0).padStart(9)}  ${s.strategy.padEnd(8)}  ${String(s.responseRows).padStart(8)}  ${s.ms.toFixed(1).padStart(7)}  ${(s.ms / Math.max(1, s.eventRowCount)).toFixed(3).padStart(6)}  ${(s.stages["event-query"] ?? 0).toFixed(1).padStart(6)}  ${(s.stages["event-json-decode"] ?? 0).toFixed(1).padStart(6)}  ${(s.stages["thread-view-projection"] ?? 0).toFixed(1).padStart(7)}`,
      );
    }
    const fullWindows = samples.filter(
      (s) => s.eventRowCount >= EVENT_BUDGET * 0.9,
    );
    const fullWindowP50 = percentile(
      fullWindows.map((s) => s.ms),
      50,
    );
    lines.push("");
    lines.push(
      `full-window builds (>= ${EVENT_BUDGET * 0.9} events, n=${fullWindows.length}): p50=${fullWindowP50.toFixed(1)}ms  target=${DOCUMENTED_COLD_BUILD_TARGET_MS}ms`,
    );
    // eslint-disable-next-line no-console
    report(lines.join("\n"));

    // The seed fixture's turns are short (8-60 items), so segmentLimit=20
    // binds before the event budget does; this scenario is informational.
    expect(samples.length).toBeGreaterThan(0);
    void fullWindows;
    void fullWindowP50;
  }, 600_000);

  it("long agentic turns: a full 1500-event window at ~1.2KB/event vs the 100ms target", () => {
    // Shape from the issue's representative logged build: eventRowCount 1257,
    // eventDataBytes 1481754 (~1179 bytes/event), 96 response rows from
    // segmentLimit 20 — i.e. very few user messages, very many events.
    const db = createConnection(":memory:");
    migrate(db);
    const host = upsertHost(db, noopNotifier, {
      name: "h",
      type: "persistent",
    });
    const { project } = createProject(db, noopNotifier, {
      name: "p",
      source: { type: "local_path", hostId: host.id, path: "/tmp/p" },
    });
    const thread = createThread(db, noopNotifier, {
      projectId: project.id,
      providerId: "codex",
    });
    insertLongAgenticTurns(db, thread, { turnCount: 6, eventsPerTurn: 500 });

    const rows: string[] = [];
    let defaultBudgetP50 = Number.NaN;
    let defaultBudgetWindowEvents = 0;
    for (const budget of [EVENT_BUDGET, 400]) {
      for (let i = 0; i < 3; i += 1) build(db, thread.id, budget);
      const runs: number[] = [];
      let last = build(db, thread.id, budget);
      for (let i = 0; i < 9; i += 1) {
        last = build(db, thread.id, budget);
        runs.push(last.profile.totalDurationMs);
      }
      const p = last.profile;
      const stages = Object.fromEntries(
        p.stageTimings.map((s) => [s.stage, s.durationMs]),
      );
      const p50 = percentile(runs, 50);
      rows.push(
        `budget=${budget}: strategy=${p.selectionStrategy} windowEvents=${p.eventRowCount} windowKiB=${(p.eventDataBytes / 1024).toFixed(0)} bytes/evt=${(p.eventDataBytes / Math.max(1, p.eventRowCount)).toFixed(0)} respRows=${p.responseRowCount} segments=${p.returnedSegmentCount} build p50=${p50.toFixed(1)}ms max=${Math.max(...runs).toFixed(1)}ms ms/evt=${(p50 / p.eventRowCount).toFixed(3)} [query=${stages["event-query"]?.toFixed(1)} decode=${stages["event-json-decode"]?.toFixed(1)} project=${stages["thread-view-projection"]?.toFixed(1)}]`,
      );
      if (budget === EVENT_BUDGET) {
        defaultBudgetP50 = p50;
        defaultBudgetWindowEvents = p.eventRowCount;
      }
    }
    // eslint-disable-next-line no-console
    report(rows.join("\n"));

    // The one assertion: the documented "cold build near 100ms" target, for a
    // window that actually fills the default budget. Passes on fast hardware,
    // fails on slow hardware — which is the issue.
    expect(defaultBudgetWindowEvents).toBeGreaterThanOrEqual(1_000);
    expect(defaultBudgetP50).toBeLessThanOrEqual(
      DOCUMENTED_COLD_BUILD_TARGET_MS,
    );
  }, 600_000);
});

/**
 * `turnCount` turns of `eventsPerTurn` events each, mixing small deltas with
 * completed command executions carrying multi-KB output, so the average stored
 * payload lands near the ~1.2KB/event the issue reports.
 */
function insertLongAgenticTurns(
  db: DbConnection,
  thread: Thread,
  shape: { turnCount: number; eventsPerTurn: number },
): void {
  const events: Parameters<typeof insertEvents>[2] = [];
  const providerThreadId = "provider-root";
  let sequence = 0;
  const push = (
    event: Omit<Parameters<typeof insertEvents>[2][number], "sequence">,
  ): void => {
    sequence += 1;
    events.push({ ...event, sequence });
  };
  const outputLine =
    "src/services/threads/timeline.ts:1234:5 - warning TS6133: 'x' is declared but its value is never read.\n";
  const output = (lines: number): string => outputLine.repeat(lines);
  const sentence =
    "I will now look at the timeline projection and the budget floor query to see why the window is not binding. ";
  const execution = {
    model: "gpt-5",
    serviceTier: "default",
    reasoningLevel: "medium",
    permissionMode: "full",
    source: "client/turn/requested",
  } as const;
  for (let turn = 1; turn <= shape.turnCount; turn += 1) {
    const turnId = `turn-${turn}`;
    const clientRequestId = encodeClientTurnRequestIdNumber({ value: turn });
    push({
      threadId: thread.id,
      type: "client/turn/requested",
      scope: threadScope(),
      itemId: null,
      itemKind: null,
      data: JSON.stringify({
        direction: "outbound",
        source: "tell",
        initiator: "user",
        request: { method: "turn/start", params: {} },
        requestId: clientRequestId,
        senderThreadId: null,
        input: [
          {
            type: "text",
            text: `Please fix the failing tests in turn ${turn}`,
            mentions: [],
          },
        ],
        target: turn === 1 ? { kind: "thread-start" } : { kind: "new-turn" },
        execution,
      }),
    });
    push({
      threadId: thread.id,
      type: "turn/started",
      scope: turnScope(turnId),
      providerThreadId,
      itemId: null,
      itemKind: null,
      data: JSON.stringify({ providerThreadId }),
    });
    push({
      threadId: thread.id,
      type: "turn/input/accepted",
      scope: turnScope(turnId),
      providerThreadId,
      itemId: null,
      itemKind: null,
      data: JSON.stringify({ clientRequestId }),
    });
    let emitted = 3;
    let item = 0;
    while (emitted < shape.eventsPerTurn - 1) {
      item += 1;
      const itemId = `${turnId}-item-${item}`;
      if (item % 3 === 0) {
        for (let d = 0; d < 3; d += 1) {
          push({
            threadId: thread.id,
            type: "item/agentMessage/delta",
            scope: turnScope(turnId),
            providerThreadId,
            itemId,
            itemKind: null,
            data: JSON.stringify({ providerThreadId, itemId, delta: sentence }),
          });
        }
        push({
          threadId: thread.id,
          type: "item/completed",
          scope: turnScope(turnId),
          providerThreadId,
          itemId,
          itemKind: "agentMessage",
          data: JSON.stringify({
            providerThreadId,
            item: { type: "agentMessage", id: itemId, text: sentence.repeat(5) },
          }),
        });
        emitted += 4;
      } else {
        const command = "pnpm exec turbo run typecheck --filter=@bb/server";
        push({
          threadId: thread.id,
          type: "item/started",
          scope: turnScope(turnId),
          providerThreadId,
          itemId,
          itemKind: "commandExecution",
          data: JSON.stringify({
            providerThreadId,
            item: {
              type: "commandExecution",
              id: itemId,
              command,
              cwd: "",
              status: "pending",
              approvalStatus: null,
              aggregatedOutput: "",
            },
          }),
        });
        for (let d = 0; d < 2; d += 1) {
          push({
            threadId: thread.id,
            type: "item/commandExecution/outputDelta",
            scope: turnScope(turnId),
            providerThreadId,
            itemId,
            itemKind: null,
            data: JSON.stringify({ providerThreadId, itemId, delta: output(8) }),
          });
        }
        push({
          threadId: thread.id,
          type: "item/completed",
          scope: turnScope(turnId),
          providerThreadId,
          itemId,
          itemKind: "commandExecution",
          data: JSON.stringify({
            providerThreadId,
            item: {
              type: "commandExecution",
              id: itemId,
              command,
              cwd: "",
              status: "completed",
              approvalStatus: null,
              aggregatedOutput: output(24),
            },
          }),
        });
        emitted += 4;
      }
    }
    push({
      threadId: thread.id,
      type: "turn/completed",
      scope: turnScope(turnId),
      providerThreadId,
      itemId: null,
      itemKind: null,
      data: JSON.stringify({ status: "completed", providerThreadId }),
    });
  }
  insertEvents(db, noopNotifier, events);
}

Root cause

Mechanism. A timeline build is synchronous work on the server's event loop: buildThreadTimeline runs inside runEventLoopWorkSync (timeline.ts#L1809-L1823). Its cost has three stages, all proportional to the amount of stored event data in the window: event-query (SQLite reads and copies the JSON text), event-json-decode (JSON.parse per row) and thread-view-projection. The only latency bound is the event-count budget resolved in resolveTimelineSegmentWindow via findTimelineWindowBudgetFloorSequence (timeline.ts#L1242-L1370, events.ts#L2471-L2491), whose default is a fixed constant:

// packages/domain/src/feature-flags.ts#L31-L37
/**
 * Measured on real threads a build costs ~0.06ms/event across the SQLite
 * read, JSON decode, and projection. 1500 keeps a cold build near 100ms; the
 * 10k-event thread that motivated the bound was ~670ms unbounded.
 */
timelineWindowEventBudget: 1_500,

An event count is a proxy for two things it does not control: (a) bytes per event, which varies with what the agent did (a 24-line command output is 2.4 KB; a delta is 150 B), and (b) CPU time per byte, which varies with the host. The comment's "0.06 ms/event" was measured once (PR #882, production bundle, presumably a developer machine) and does not travel. On this workstation the true figure is 0.024 ms/event at 0.9 KB/event; under a 25% share of one core it is 0.083–0.12; the reporter sees ~0.5 (with the sampling caveat above). Since the budget is what keeps the daemon's /internal/session/events round trip fast (the whole reason PR #882 exists), on slow hosts the bound is simply too loose to do its job.

Why the symptom is sustained rather than incidental. The build cache is keyed by maxSeq (timeline-cache.ts#L124-L129), the client schedules a trailing refetch whenever an events-appended signal lands, and even the delta path reprojects the full window first (data.ts#L363-L378). The client does not refetch once per event, though: resolveTrailingRefetchDelayMs waits out the observed fetch duration (min 50 ms, max 1 s) before the next refetch and coalesces events that arrived meanwhile (realtime-cache-registry.ts#L135-L157), which caps the server-side duty cycle near 50%. So while a long thread is being viewed during a streaming turn, the server pays the full-window cost repeatedly for the whole turn — sustained, but coalesced to roughly one build per build-duration. On a fast host that is ~30 ms every ≥50 ms; on the reporter's host each build is several hundred ms, so the loop is blocked about half the time the turn streams, which matches "1656 slow builds, 155 s blocked in one session" (~94 ms average per slow build).

Deeper issue. There is already a second, byte-based cut in the same pipeline: applyTimelineWindowByteBudget caps a window at THREAD_TIMELINE_EVENT_DATA_BYTE_LIMIT = 4 MiB (timeline.ts#L177, #L1052-L1118, floor query events.ts#L2714-L2785). It was added as a memory guard (#1199), is not operator-tunable, and at 4 MiB it never engages for latency. Bytes are the better proxy for the two dominant stages, and the machinery to cut on them already exists and is tested. The remaining hardware term (ms per byte) can only be handled by measuring on the host or by getting the work off the event loop. To be fair to the original author: PR #882's own "Known limits" section already states "The budget bounds event count, not bytes" and "1500 is a first guess from cost-per-event … The new logs are how we'll tune it" — so the count-vs-bytes gap was anticipated, and this issue is the first tuning signal those logs were meant to produce; what was not anticipated is that the per-event cost varies ~10x across hosts.

Proposed fix (first principles)

Cheapest change that addresses the actual cost driver, no new machinery:

  1. Promote the existing 4 MiB byte cap to a feature flag timelineWindowByteBudget (env BB_FF_TIMELINE_WINDOW_BYTE_BUDGET) next to timelineWindowEventBudget, and pass it into applyTimelineWindowByteBudget the same way eventBudget is threaded today (server-side only: packages/domain/src/feature-flags.ts, packages/config/src/feature-flags.ts + env-vars.ts, apps/server/src/routes/threads/data.ts, timeline.ts). Default it to something that binds for latency, e.g. 1.5 MiB (≈ 1500 events × 1 KB, i.e. what the current default already implies), and keep the 4 MiB memory guard as the upper clamp. Document both knobs together in docs/configuration.md, the guide template and the bb-cli skill (AGENTS.md requires all surfaces in one change).
  2. Reword the source comment to say the count is a proxy and hardware dependent, and point operators at the two knobs and at the Thread timeline build blocked the event loop line — while noting that line samples only builds ≥ 150 ms.

What could go wrong. (a) A byte cut can split a finished turn (the event-count cut only splits running turns; see the comment on resolveTimelineWindowBounds), so lowering the byte default changes paging UX for threads with huge single turns — the byte-cursor path exists and is tested (#1199), but the default would engage far more often than today, so the pagination suites need to run against the new default. (b) The timeline caches deliberately do not key on the budget (comment at data.ts#L329-L333); a byte flag resolved once at startup keeps that invariant, but any adaptive scheme (issue option 1: calibrate at runtime) must add the effective budget to the cache and latest-rows keys or a client echoing afterSequence will get deltas against a different row set. That is why I would not start with runtime calibration. (c) Neither knob fixes the structural cost — full reprojection per appended event on the event loop; incremental projection or a worker thread is the real fix and is out of scope for this issue.

Not needed to settle: the mechanism is clear. What would sharpen the numbers: run the repro test on the reporter's host (or any 2–4 vCPU VM) to get an unbiased ms/event and ms/KiB, rather than deriving them from the ≥150 ms log lines.

PR review

#1756 — docs: record that the timeline event budget is hardware dependent (open, by the issue author)

What it changes. 14 lines, two files (pr1756.diff): appends a paragraph to the timelineWindowEventBudget JSDoc in packages/domain/src/feature-flags.ts reproducing the VPS numbers (0.479/0.964/5.55 ms/event, 541 samples, "roughly 8x", "~720 ms"), and inserts a few sentences into docs/configuration.md "Thread Timeline Window" telling operators to divide a logged build's totalDurationMs by eventRowCount and lower the budget. No behavior change; the default stays 1500.

Does it address the root cause? No, and it says so. It papers over nothing either; it is a note. Checked out (gh pr checkout 1756), pnpm exec turbo run typecheck --filter=@bb/domain passes; there is nothing to test.

File:lineSeverityFinding
packages/domain/src/feature-flags.ts:37-43MediumBakes one host's measurements (core count, RAM, sample count, three percentiles) into a shared-domain source comment. Those numbers are (a) unverifiable, (b) derived from a ≥150 ms-only sample and thus biased upward (see Claims), and (c) already stale the day the reporter upgrades or the projection changes. A source comment should state the invariant ("count is a proxy; per-event cost is host- and payload-dependent; see docs") not a dataset. On my hardware the comment's new "roughly 8x" is off in the other direction (the default is 2.5x conservative), so the comment would mislead in both directions.
docs/configuration.md:640-646LowThe operator recipe "divide totalDurationMs by eventRowCount" is fine as a heuristic but the doc should say the line only appears for builds ≥ 150 ms and once per thread per 30 s, so the ratio is a slow-tail estimate. It should also mention that a whole finished turn is always returned even if larger than the budget (so lowering the budget below the typical turn size does not shrink the window further; my run: budget 400 → 500-event window). Also, the sentence was inserted mid-line into an already over-wide line and "Older turns load automatically" now dangles across a wrap — cosmetic.
docs/configuration.md (whole)LowPR body offers two follow-ups (startup calibration, or budgeting on bytes). The byte-based cut already exists at 4 MiB (applyTimelineWindowByteBudget) — the doc could point at that as the real lever instead of leaving the reader to tune an event count. Startup calibration is the riskier option because of the cache-key invariant noted above.
ProcessInfoMissing the > AGENT GENERATED: by ... footer required by AGENTS.md if the text was agent-written (the phrasing suggests it may be); the PR body says "Refs #1749" rather than fixing it, which is accurate. No HOST_DAEMON_PROTOCOL_VERSION concern (no wire change). No security implications.

Verdict: REQUEST CHANGES. Harmless but low value as written. Trim the source comment to one hardware-independent sentence pointing at the docs; keep the docs paragraph, add the sampling caveat and the "whole finished turn" caveat, and either land the byte-budget knob in the same change or state that as the follow-up. If maintainers prefer zero doc churn until a real fix, CLOSE in favor of the byte-budget change is also reasonable.

Related issues

Appendix

Commands run

gh issue view 1749 --comments            # no comments at time of investigation
gh pr view 1756; gh pr diff 1756
pnpm install --frozen-lockfile --prefer-offline
pnpm exec turbo run build                # 14 tasks, 10 cached
git fetch origin main; git log 16ceb3a54..origin/main --oneline -- apps/server/src/services/threads packages/domain/src/feature-flags.ts docs/configuration.md   # empty
cp 1749/repro/timeline-event-budget-cost.repro.test.ts apps/server/test/services/threads/
cd apps/server && REPRO_1749_OUT=/tmp/bb-reports/issues/1749/repro-output-main.txt pnpm exec vitest run test/services/threads/timeline-event-budget-cost.repro.test.ts   # 2 passed
bash 1749/repro/run-contended.sh <worktree> /tmp/bb-reports/issues/1749/repro-output-contended.txt   # 1 failed (124.5 > 100)
git stash -u; gh pr checkout 1756; pnpm exec turbo run typecheck --filter=@bb/domain; git diff 16ceb3a54 > 1749/pr1756.diff; git checkout 16ceb3a54; git stash pop

Full idle-run output

host: x64 node v24.18.0
threads=60 budget=1500 threadsWhereBudgetBinds=20
ms/event (threads>=200 events, n=44): p50=0.028 p90=0.032 max=0.033  (documented: 0.06)
ms/KiB  (same threads): p50=0.053 p90=0.063

threadEvents  windowEvents  windowKiB  bytes/evt  strategy  respRows  buildMs  ms/evt   query  decode  project
        1512           908        483        545  standard-window       100     23.6   0.026    13.1     8.9      2.8
        2210           876        448        523  standard-window       106     24.8   0.028     8.2    12.8      2.5
        2668           866        511        604  standard-window        93     23.9   0.028     9.8     9.1      3.0
        2227           863        463        549  standard-window        87     21.6   0.025     8.4     8.9      3.0
        2424           855        463        555  standard-window        71     23.9   0.028     7.9     8.6      2.9
        1857           851        422        508  standard-window        84     20.0   0.024     7.5    13.1      2.8
        1528           833        437        537  standard-window        94     21.3   0.026     8.8     8.1      2.3
        2014           817        415        521  standard-window        96     22.5   0.028     8.9     8.9      2.9
        3074           811        445        561  standard-window       105     23.6   0.029     9.4     7.9      2.8
        2333           805        385        490  standard-window        85     21.1   0.026     9.9     9.4      3.0
        1120           788        418        544  standard-window        86     18.7   0.024     6.3     8.0      2.6
        2169           775        416        549  standard-window        71     24.6   0.032     9.6    13.6      2.7
        1968           772        392        520  standard-window        89     25.4   0.033    12.6     8.1      3.1
        2759           768        393        524  standard-window        79     21.8   0.028    14.5     7.6      2.4
        2377           762        378        508  standard-window        74     21.4   0.028     8.5     9.0      2.3
         855           735        356        496  standard-window        63     19.2   0.026     5.4     7.5      2.4
        2359           732        373        521  standard-window        73     17.8   0.024     7.1     7.1      2.0
        1168           731        379        531  standard-window       100     18.0   0.025     6.4     7.8      2.3
         768           711        360        519  standard-window        74     16.8   0.024     5.1    12.6      3.5
        1784           699        328        480  standard-window        67     17.5   0.025    10.7     6.9      2.6
        1799           697        344        505  standard-window        73     21.8   0.031     6.8     7.7      2.5
        1839           696        353        519  standard-window        72     19.5   0.028     7.4     7.8      2.8
        3230           684        325        487  standard-window        59     18.9   0.028     8.2     7.0      1.9
        2419           649        336        530  standard-window        84     19.6   0.030     7.7    11.0      2.0
         688           640        338        541  standard-window        66     17.9   0.028     6.4     8.1      2.6

full-window builds (>= 1350 events, n=0): p50=0.0ms  target=100ms

budget=1500: strategy=standard-window windowEvents=1500 windowKiB=1302 bytes/evt=889 respRows=12 segments=3 build p50=36.4ms max=48.1ms ms/evt=0.024 [query=19.8 decode=22.1 project=5.1]
budget=400: strategy=standard-window windowEvents=500 windowKiB=434 bytes/evt=889 respRows=4 segments=1 build p50=12.1ms max=15.8ms ms/evt=0.024 [query=5.5 decode=7.7 project=2.1]

Full contended-run output

host: x64 node v24.18.0
threads=60 budget=1500 threadsWhereBudgetBinds=20
ms/event (threads>=200 events, n=44): p50=0.119 p90=0.146 max=0.167  (documented: 0.06)
ms/KiB  (same threads): p50=0.237 p90=0.285

threadEvents  windowEvents  windowKiB  bytes/evt  strategy  respRows  buildMs  ms/evt   query  decode  project
        1512           908        483        545  standard-window       100    104.9   0.116    42.5    43.0     21.5
        2210           876        448        523  standard-window       106     92.3   0.105    27.0    36.0     11.8
        2668           866        511        604  standard-window        93    103.3   0.119    40.8    47.1     13.6
        2227           863        463        549  standard-window        87    144.2   0.167    49.4    59.6     24.3
        2424           855        463        555  standard-window        71    104.6   0.122    36.3    63.2     13.5
        1857           851        422        508  standard-window        84     92.8   0.109    33.4    36.9     12.0
        1528           833        437        537  standard-window        94     95.5   0.115    35.6    36.8     12.2
        2014           817        415        521  standard-window        96    110.6   0.135    38.1    59.9     13.1
        3074           811        445        561  standard-window       105    126.8   0.156    36.6    47.9     46.5
        2333           805        385        490  standard-window        85     95.3   0.118    35.8    35.9     11.8
        1120           788        418        544  standard-window        86     80.7   0.102    24.1    35.2     11.4
        2169           775        416        549  standard-window        71     83.4   0.108    34.2    35.5     11.6
        1968           772        392        520  standard-window        89     86.1   0.112    36.2    34.8     11.8
        2759           768        393        524  standard-window        79     94.4   0.123    36.6    35.4     11.6
        2377           762        378        508  standard-window        74    111.2   0.146    64.2    48.2     12.7
         855           735        356        496  standard-window        63     71.4   0.097    23.3    65.5      8.3
        2359           732        373        521  standard-window        73     88.9   0.121    54.9    35.5     11.9
        1168           731        379        531  standard-window       100     79.8   0.109    24.7    34.4     13.6
         768           711        360        519  standard-window        74     82.0   0.115    21.8    49.2     15.8
        1784           699        328        480  standard-window        67     92.9   0.133    35.8    35.2     12.9
        1799           697        344        505  standard-window        73     85.6   0.123    34.7    65.3     11.5
        1839           696        353        519  standard-window        72     79.5   0.114    25.0    25.6      2.2
        3230           684        325        487  standard-window        59     91.1   0.133    36.6    35.4     11.3
        2419           649        336        530  standard-window        84     82.8   0.128    25.3    25.6      2.4
         688           640        338        541  standard-window        66     67.3   0.105    20.9    34.3     11.0

full-window builds (>= 1350 events, n=0): p50=0.0ms  target=100ms

budget=1500: strategy=standard-window windowEvents=1500 windowKiB=1302 bytes/evt=889 respRows=12 segments=3 build p50=124.5ms max=140.7ms ms/evt=0.083 [query=44.6 decode=73.0 project=22.1]
budget=400: strategy=standard-window windowEvents=500 windowKiB=434 bytes/evt=889 respRows=4 segments=1 build p50=41.0ms max=67.5ms ms/evt=0.082 [query=12.5 decode=22.7 project=1.2]

PR #1756 diff

diff --git a/docs/configuration.md b/docs/configuration.md
index 0eb5715ee..000f27e89 100644
--- a/docs/configuration.md
+++ b/docs/configuration.md
@@ -637,7 +637,13 @@ is synchronous, so it blocked the server's event loop — which also delayed
 dynamic tool call and before registering every interactive request. One slow
 thread therefore slowed agent work on _every_ thread on the host.
 
-A window is capped at `BB_FF_TIMELINE_WINDOW_EVENT_BUDGET` events (default 1500) and returns however many whole turns fit. Older turns load automatically
+A window is capped at `BB_FF_TIMELINE_WINDOW_EVENT_BUDGET` events (default 1500) and returns however many whole turns fit. The default assumes roughly
+0.06ms per event; that cost varies widely with hardware, and on a small VPS it
+can be closer to 0.5ms, making a full window ~720ms of blocked event loop
+instead of ~100ms. If `Thread timeline build blocked the event loop` appears
+often, divide a logged build's `totalDurationMs` by its `eventRowCount` to get
+your real per-event cost and lower this budget until a full window fits your
+latency target. Older turns load automatically
 as you scroll toward the top of the loaded window; a manual "Load older
 messages" button remains on surfaces that render no scroll body, and after a
 failed page so a broken fetch is retried on request rather than in a loop.
diff --git a/packages/domain/src/feature-flags.ts b/packages/domain/src/feature-flags.ts
index 7f1902f91..e0fdcce75 100644
--- a/packages/domain/src/feature-flags.ts
+++ b/packages/domain/src/feature-flags.ts
@@ -33,6 +33,13 @@ export const defaultFeatureFlags: FeatureFlags = {
    * Measured on real threads a build costs ~0.06ms/event across the SQLite
    * read, JSON decode, and projection. 1500 keeps a cold build near 100ms; the
    * 10k-event thread that motivated the bound was ~670ms unbounded.
+   *
+   * That per-event cost is hardware dependent and the spread is wide: on a
+   * 4-core / 4.9 GiB VPS it measures 0.479ms/event at p50 (p90 0.964,
+   * max 5.55) across 541 samples, roughly 8x the figure above, which puts a
+   * full 1500-event build near 720ms of blocked event loop rather than 100ms.
+   * Operators on modest hardware should lower this via
+   * BB_FF_TIMELINE_WINDOW_EVENT_BUDGET; see docs/configuration.md.
    */
   timelineWindowEventBudget: 1_500,
 };

Things checked and ruled out

Verification

An independent verifier followed the report literally in a fresh worktree at 16ceb3a54: install + build, copied the repro test into apps/server/test/services/threads/, ran it idle (2 passed; budget=1500 window p50=30.0 ms, 0.020 ms/event; budget=400 → 500-event window p50=9.6 ms) and via run-contended.sh (1 failed: expected 141.9 to be less than or equal to 100, ms/event p50 0.189). All permalinks and code excerpts were checked as real at the base commit; gh pr diff 1756 matched the saved diff; nothing later on origin/main touches these paths. Verifier outputs: verify/repro-output-main-verify.txt, verify/repro-output-contended-verify.txt.

Changes made in this revision.

Verdict, root cause, proposed fix and the PR #1756 review are unchanged.