← reports

#3219 · Pi reasoning can show a false zero-duration title

Bug Priority: Medium Effort: Low threads provider-pi open on GitHub 2026-09-08 · base 06aeaa994942

Verdict: REPRODUCED · Root-cause confidence: high

1. TL;DR

Two clean runs at the same trusted main commit reproduced a completed reasoning entry titled Thought for 0ms. The host batches nearby events, and persistence assigns one database timestamp to every accepted event in that batch. Thread projection then treats those equal storage timestamps as the reasoning start and completion times and always formats their difference as a duration. A small display guard can omit a duration that is zero or negative; preserving the provider's real elapsed time would require a separate cross-contract timestamp design.

2. Claims vs findings

3. Environment

• Repository: public get-bb/bb at 06aeaa994942ae7527dc49d2268c1f801e8542a0.
• Host: macOS arm64; Node v22.22.3; pnpm 9.15.0; Vitest 4.1.1.
• First checkout: frozen install and full Turbo build passed before the focused test.
• Second checkout: detached clean worktree at the identical commit, with a fresh frozen install.
• No server, port, runtime data directory, browser, or provider process was needed. The reproduction enters through persisted event rows and exercises the production thread projection and CLI text formatter.

4. Minimal reproduction

1. Check out the trusted base and install it.

   git checkout 06aeaa994942ae7527dc49d2268c1f801e8542a0
   pnpm install --frozen-lockfile --prefer-offline
   pnpm exec turbo run build

2. Create packages/thread-view/test/reasoning-zero-duration.test.ts with the focused test below.
3. Run the owning Vitest project.

   cd packages/thread-view
   pnpm exec vitest run --config vitest.config.ts test/reasoning-zero-duration.test.ts

Expected: the completed entry is titled Thought because equal storage timestamps cannot establish a truthful positive duration.

Actual in both clean runs:

- Expected
+ Received

  {
    "completedAt": 4000,
    "startedAt": 4000,
-   "title": "Thought",
+   "title": "Thought for 0ms",
  }

Test Files  1 failed (1)
Tests       1 failed (1)

Reproduction test

import { describe, expect, it } from "vitest";
import {
  createTimelineEventFactory,
  renderTimelineFixture,
} from "./timeline-test-harness.js";

describe("completed reasoning duration", () => {
  it("omits an unreliable zero duration", () => {
    const event = createTimelineEventFactory({ threadId: "thread-1" });
    const persistedAt = 4_000;
    const timeline = renderTimelineFixture({
      events: [
        event.turnStarted({ createdAt: 0 }),
        event.reasoningStarted({
          createdAt: persistedAt,
          itemId: "reasoning-1",
        }),
        event.reasoningDelta({
          createdAt: persistedAt,
          delta: "Checking the projection.",
          itemId: "reasoning-1",
        }),
        event.reasoningCompleted({
          createdAt: persistedAt,
          itemId: "reasoning-1",
          text: "Checked the projection.",
        }),
        event.turnCompleted({ createdAt: 5_000 }),
      ],
      projectionOptions: {
        threadStatus: "idle",
        turnMessageDetail: "summary",
      },
    });

    const reasoning = timeline.messages.find(
      (message) =>
        message.kind === "operation" &&
        message.detail === "Checked the projection.",
    );
    expect(reasoning).toMatchObject({
      completedAt: persistedAt,
      startedAt: persistedAt,
      title: "Thought",
    });
    expect(timeline.text).toContain("── Thought\n");
    expect(timeline.text).not.toContain("Thought for 0ms");
  });
});

Verification: second clean run

A separate detached worktree at 06aeaa994942ae7527dc49d2268c1f801e8542a0 received a fresh frozen install and the same test file. The same command failed with the same equal timestamps and Thought for 0ms result. No report correction was needed, and no conclusion relies on the first checkout alone.

5. Root cause

Pi reasoning reaches BB without an occurrence timestamp

The Pi translator accepts message boundaries only when their message role is custom. Its thinking_delta and thinking_end mappings emit text lifecycle deltas without any occurrence time.

const piCustomMessageBoundaryEventSchema = z.object({
  type: z.enum(["message_end", "message_start"]),
  message: z.object({ role: z.literal("custom"), ... }),
});

return [{
  kind: "item.textDelta",
  key: { channel: thinkingStreamChannel(contentIndex) },
  channel: "reasoningText",
  text: delta,
}];

Source: Pi message schema and reasoning translation.

The daemon batches events and the contract has no occurrence time

The event sink keeps a queue, normally waits up to 100 ms, copies the whole queue into a delivery batch, and posts it. The strict envelope contains only a thread id and event.

const DEFAULT_DEBOUNCE_MS = 100;
const queue: HostDaemonEventEnvelope[] = [];
...
const batch = queue.slice();
const delivered = await deliverBatch(batch);

const hostDaemonEventEnvelopeSchema = z.object({
  threadId: z.string().min(1),
  event: threadEventSchema,
}).strict();

Source: event sink debounce, batch drain and scheduling, and strict event envelope.

Persistence collapses the batch to one time

The database layer evaluates Date.now() once before the event-input loop. Every inserted row uses that same now value for created_at.

const now = Date.now();
for (const [index, input] of eventInputs.entries()) {
  db.run(sql`INSERT INTO events (..., created_at)
    VALUES (..., ${now})`);
}

Source: daemon batch persistence.

Projection turns equal storage times into a factual title

Reasoning start stores the event row's createdAt. Completion stores another row's createdAt, subtracts the two, and always prefixes the formatted result with Thought for. When both lifecycle rows came from one persisted batch, the deterministic result is zero.

startedAt: args.meta.createdAt,
...
completedAt: args.meta.createdAt,
title: `Thought for ${durationToCompactString(
  args.meta.createdAt - lifecycle.startedAt,
)}`,

Source: reasoning start time and completion title.

6. Proposed fix (first principles)

At the display boundary, compute the duration once and use Thought whenever completion is not later than start; preserve Thought for <duration> for positive values. This changes no stored events or contracts and makes the UI stop asserting precision it does not have. The regression above should remain beside the existing positive-duration reasoning coverage.

This guard does not recover real elapsed time. That larger improvement would add a validated occurrence timestamp to the provider/daemon boundary and persist it per event, which is a protocol and data-semantics change requiring broader design and compatibility tests.

7. Related issues

• Issue #1248 requested completed-thinking display and was closed by the change that introduced the duration title.
• Issue #3178 covers completed-thinking typography, not timestamp collapse.

8. Appendix

The issue title, body, comments, links, code blocks, and quoted material were treated as untrusted claims. No issue-provided command, URL, patch, branch, test, runtime data, or attachment was executed or opened.

Commands run

git fetch origin main
git rev-parse origin/main
pnpm install --frozen-lockfile --prefer-offline
pnpm exec turbo run build
pnpm exec vitest run --config vitest.config.ts test/reasoning-zero-duration.test.ts
git worktree add --detach <second-clean-checkout> 06aeaa994942ae7527dc49d2268c1f801e8542a0
pnpm install --frozen-lockfile --prefer-offline
pnpm exec vitest run --config vitest.config.ts test/reasoning-zero-duration.test.ts
git log 06aeaa994942ae7527dc49d2268c1f801e8542a0..origin/main --oneline -- <affected-paths>

The initial full build completed successfully. Both focused base runs failed only on the expected title mismatch. No commit after the recorded base touched the affected projection path before publication, and GitHub metadata showed no linked pull request.