diff --git a/src/client/components/statsTiming.tsx b/src/client/components/statsTiming.tsx index b7c6ae3..86b7b68 100644 --- a/src/client/components/statsTiming.tsx +++ b/src/client/components/statsTiming.tsx @@ -7,10 +7,10 @@ * lands in the residue. When the host folded the generation split (see * TimingTotals), the generation slice expands into what was being decoded: * thinking, answer text, and tool-call arguments. The slice rows lead with - * the true duration and qualify it with the call count on the secondary line — - * except the decode slices, which count BLOCKS (zero to many per call, so a - * call count would be a false tally) and therefore carry no qualifier. A slice - * that never happened (zero time) is omitted entirely — the ring already skips + * the true duration and qualify it with a tally on the secondary line — the + * model calls (TTFT), the tool runs, and the decode slices' own BLOCK counts + * (zero to many per call, so a call count would be a false tally there). A + * slice that never happened (zero time) is omitted entirely — the ring already skips * its arc, and a zero row would otherwise borrow the session's call count and * read as "no time, many calls". The donut and the rows sit side by side so * the head row stays half-height. Parallel tool calls each count, so the tools @@ -33,7 +33,7 @@ interface Slice { label: string /** The TRUE duration (the row prints this; the ring clamps it into its window). */ ms: number - /** The secondary-line qualifier (a call count), absent when there is none. */ + /** The secondary-line qualifier (a call/run/block tally), absent when there is none. */ times?: string } @@ -90,19 +90,25 @@ export function makeStatsTiming(kit: ViewKit, Donut: (props: DonutProps) => Reac // (all-zero buckets) keeps the un-split shape instead of three dead rows. // An absent bucket reads as 0 (the host omits a zero span). // - // These slices carry NO call-count qualifier: they count DECODE BLOCKS, - // and one model call emits zero to many of them (a single call routinely - // requests several tools, and most calls emit no reasoning at all), so - // the call count would read as a per-slice tally that is simply untrue. - // TTFT and tools keep theirs — those happen exactly once per call/run. - const buckets: [key: string, color: string, label: string, ms: number][] = [ - ['reasoning', COLOR.reasoning, t('timing.reasoning'), timing.reasoningMs ?? 0], - ['text', COLOR.text, t('timing.text'), timing.textMs ?? 0], - ['toolarg', COLOR.toolarg, t('timing.toolArgs'), timing.toolArgMs ?? 0], + // These slices qualify with their own BLOCK tally, never the call + // count: one model call emits zero to many decode blocks (a single call + // routinely requests several tools, and most calls emit no reasoning at + // all), so the call count would read as a per-slice tally that is simply + // untrue. TTFT and tools keep theirs — those happen exactly once per + // call/run. A host that folded no counts (an older cached row) serves + // the duration alone. + const blockTimes = (blocks?: number): string | undefined => + blocks !== undefined && blocks > 0 ? t('timing.blockTimes', { n: fmt(blocks) }) : undefined + const buckets: [key: string, color: string, label: string, ms: number, times?: string][] = [ + ['reasoning', COLOR.reasoning, t('timing.reasoning'), timing.reasoningMs ?? 0, blockTimes(timing.reasoningBlocks)], + ['text', COLOR.text, t('timing.text'), timing.textMs ?? 0, blockTimes(timing.textBlocks)], + ['toolarg', COLOR.toolarg, t('timing.toolArgs'), timing.toolArgMs ?? 0, blockTimes(timing.toolArgBlocks)], ] const split = buckets.some(([, , , ms]) => ms > 0) if (split) { - for (const [key, color, label, ms] of buckets) modelSlices.push({ key, color, label, ms }) + for (const [key, color, label, ms, times] of buckets) { + modelSlices.push({ key, color, label, ms, ...(times !== undefined ? { times } : {}) }) + } } else { modelSlices.push({ key: 'gen', color: COLOR.reasoning, label: t('timing.gen'), ms: timing.genMs }) } diff --git a/src/client/i18n.ts b/src/client/i18n.ts index 3a220ef..bd9757d 100644 --- a/src/client/i18n.ts +++ b/src/client/i18n.ts @@ -41,7 +41,7 @@ export const DICT_ZH: Record = { 'timing.toolArgs': '工具参数', 'timing.tools': '工具执行', 'timing.other': '其他开销', - 'timing.callTimes': '{n}次', 'timing.toolTimes': '{n}次', + 'timing.callTimes': '{n}次', 'timing.toolTimes': '{n}次', 'timing.blockTimes': '{n}次', 'timing.empty': '暂无耗时数据 · 对话开始后这里会显示时长分布', 'timing.tps': '{tps} tok/s', 'timing.tpsTip': '输出速度(TPS):累计解码输出 tokens ÷ 累计解码时长,与 DeepSeek Harness 会话统计同口径。', @@ -330,7 +330,7 @@ export const DICT_EN: Record = { 'timing.toolArgs': 'Tool args', 'timing.tools': 'Tool runs', 'timing.other': 'Overhead', - 'timing.callTimes': '{n} calls', 'timing.toolTimes': '{n} runs', + 'timing.callTimes': '{n} calls', 'timing.toolTimes': '{n} runs', 'timing.blockTimes': '{n} blocks', 'timing.empty': 'No timing data yet — durations appear as the conversation runs', 'timing.tps': '{tps} tok/s', 'timing.tpsTip': 'Output speed (TPS): summed decoded output tokens over summed decode time — the same pairing as the harness session stats.', diff --git a/src/client/services.ts b/src/client/services.ts index 5cc5e32..d616608 100644 --- a/src/client/services.ts +++ b/src/client/services.ts @@ -569,11 +569,12 @@ function msNumOf(value: unknown): number { } /** - * The OPTIONAL timing scalars (the generation split): a real non-negative - * number passes, anything else — including absence — reads as undefined so the - * field stays absent on the narrowed value (see `timingOf`). + * The OPTIONAL timing scalars (the generation split's spans and block counts): + * a real non-negative number passes, anything else — including absence — reads + * as undefined so the field stays absent on the narrowed value (see + * `timingOf`). */ -function optMsNumOf(value: unknown): number | undefined { +function optNumOf(value: unknown): number | undefined { return typeof value === 'number' && Number.isFinite(value) && value >= 0 ? value : undefined } @@ -590,10 +591,10 @@ function timingFastOk(value: unknown): boolean { for (const k of ['wallMs', 'ttftMs', 'genMs', 'calls', 'toolsMs', 'toolCalls']) { if (typeof t[k] !== 'number') return false } - // The generation split is optional but, when present, must be a finite - // non-negative number — the same gate the slow path applies, so a hostile - // bucket cannot slip through the fast path (see `timingOf`). - for (const k of ['reasoningMs', 'textMs', 'toolArgMs']) { + // The generation split and the block counts are optional but, when present, + // must be finite non-negative numbers — the same gate the slow path applies, + // so a hostile bucket cannot slip through the fast path (see `timingOf`). + for (const k of ['reasoningMs', 'textMs', 'toolArgMs', 'reasoningBlocks', 'textBlocks', 'toolArgBlocks']) { const v = t[k] if (v !== undefined && (typeof v !== 'number' || !Number.isFinite(v) || v < 0)) return false } @@ -642,15 +643,21 @@ export function timingOf(value: unknown): TimingTotals | null { toolCalls: msNumOf(data.toolCalls), tools, } - // The generation split stays ABSENT when the host did not serve it (a row - // cached before the split) or served a non-number: the card then renders the - // un-split shape instead of three meaningless zero rows. - const reasoning = optMsNumOf(data.reasoningMs) + // The optional scalars stay ABSENT when the host did not serve them (a row + // cached before the split / the counts) or served a non-number: the card + // renders the un-split shape / no qualifier instead of meaningless zeros. + const reasoning = optNumOf(data.reasoningMs) if (reasoning !== undefined) totals.reasoningMs = reasoning - const textMs = optMsNumOf(data.textMs) + const reasoningBlocks = optNumOf(data.reasoningBlocks) + if (reasoningBlocks !== undefined) totals.reasoningBlocks = reasoningBlocks + const textMs = optNumOf(data.textMs) if (textMs !== undefined) totals.textMs = textMs - const toolArgMs = optMsNumOf(data.toolArgMs) + const textBlocks = optNumOf(data.textBlocks) + if (textBlocks !== undefined) totals.textBlocks = textBlocks + const toolArgMs = optNumOf(data.toolArgMs) if (toolArgMs !== undefined) totals.toolArgMs = toolArgMs + const toolArgBlocks = optNumOf(data.toolArgBlocks) + if (toolArgBlocks !== undefined) totals.toolArgBlocks = toolArgBlocks return totals } diff --git a/src/host/fold.ts b/src/host/fold.ts index e9230e4..a6f6957 100644 --- a/src/host/fold.ts +++ b/src/host/fold.ts @@ -34,8 +34,8 @@ import { } from './pricing' import type { ContentBlock, MessageSource } from './pricing' import { deriveEventMessage } from '@deepseek-ai/dsh-session' -import { decodeKindOfBlock, decodeSpansOfStream, firstTokenTimeOfStream, isTokenChunk, replaceRangeOf } from './logShapes' -import type { DecodeKind } from './logShapes' +import { decodeKindOfBlock, decodeTallyOfStream, firstTokenTimeOfStream, isTokenChunk, replaceRangeOf } from './logShapes' +import type { DecodeCounts, DecodeKind } from './logShapes' import { opBearingTool, opsOfCall, parseCallArgs, rawArgsNeeded } from '../shared/fileOps' /** @@ -178,13 +178,21 @@ export interface TimelineState { * durations, never to unbounded state. Same arm/remove lifecycle as * `pendingShadowedSeqs`. * - * `decode` and `block` carry the generation split (reasoning / answer text / - * tool arguments — see TimingTotals): a V0 log's `assistant/chunk` - * `block-start` markers open `block` and close the previous one into - * `decode`; a V2+ log carries no such events, so `decode` stays absent and - * `assistant/message` reads the spans off its embedded stream instead. + * `decode`, `blocks` and `block` carry the generation split (reasoning / + * answer text / tool arguments — see TimingTotals): a V0 log's + * `assistant/chunk` `block-start` markers open `block`, close the previous + * one into `decode`, and count the opened bucket into `blocks` (the card's + * per-slice tally); a V2+ log carries no such events, so `decode` stays + * absent and `assistant/message` reads the spans and counts off its embedded + * stream instead. */ - stepStart?: { time: number; firstToken?: number; decode?: Record; block?: { kind: DecodeKind; since: number } } + stepStart?: { + time: number + firstToken?: number + decode?: Record + blocks?: DecodeCounts + block?: { kind: DecodeKind; since: number } + } /** * Tool callId → the call's name, start instant, and raw arguments, armed by * `tool/call` and DELETED when its `tool/result` folds in (one result per @@ -773,17 +781,24 @@ function ensureTiming(st: TimelineState): TimingTotals { return st.timing } +/** The TimingTotals fields each decode bucket's span and count land in. */ +const DECODE_FIELDS: Record = { + reasoning: { ms: 'reasoningMs', n: 'reasoningBlocks' }, + text: { ms: 'textMs', n: 'textBlocks' }, + toolarg: { ms: 'toolArgMs', n: 'toolArgBlocks' }, +} + /** - * Fold one block's decode span into the totals' generation split (see - * TimingTotals). A zero span stays ABSENT — the field then carries the - * "no time was decoded in this bucket" fact without adding dead properties to - * every pre-split-shaped state, and the card reads absence as 0. + * Fold one block's decode span and count into the totals' generation split + * (see TimingTotals). A zero span or count stays ABSENT — the field then + * carries the "nothing was decoded/counted in this bucket" fact without adding + * dead properties to every pre-split-shaped state, and the card reads absence + * as 0. */ -function addDecode(timing: TimingTotals, kind: DecodeKind, ms: number): void { - if (!(ms > 0)) return - if (kind === 'reasoning') timing.reasoningMs = (timing.reasoningMs ?? 0) + ms - else if (kind === 'text') timing.textMs = (timing.textMs ?? 0) + ms - else timing.toolArgMs = (timing.toolArgMs ?? 0) + ms +function addDecode(timing: TimingTotals, kind: DecodeKind, ms: number, blocks: number): void { + const field = DECODE_FIELDS[kind] + if (ms > 0) timing[field.ms] = (timing[field.ms] ?? 0) + ms + if (blocks > 0) timing[field.n] = (timing[field.n] ?? 0) + blocks } /** @@ -1026,12 +1041,17 @@ export function applyTimeline(state: TimelineState, event: TimelineEvent, bounds const s = ensure([]) const decode = { ...(start.decode ?? { reasoning: 0, text: 0, toolarg: 0 }) } if (start.block !== undefined) decode[start.block.kind] += durOf(start.block.since, event.time) + // A known-kind marker is one counted decode block (the card's + // per-slice tally); the unknown one counted nothing. + const blocks = { ...(start.blocks ?? { reasoning: 0, text: 0, toolarg: 0 }) } + if (kind !== undefined) blocks[kind] += 1 // The next block is ABSENT (not undefined-valued) when unknown — the // plain-JSON persisted-state precondition (see TimelineState). s.stepStart = { time: start.time, ...(start.firstToken !== undefined ? { firstToken: start.firstToken } : {}), decode, + blocks, ...(kind !== undefined ? { block: { kind, since: event.time } } : {}), } break @@ -1294,11 +1314,11 @@ export function applyTimeline(state: TimelineState, event: TimelineEvent, bounds timing.speedTokens = (timing.speedTokens ?? 0) + output } // Generation split: a V0 log's chunk stream accumulated the block - // spans in the slot (its last block closes HERE, at the message); - // a V2+ log has no chunk events, so the spans come off the embedded - // stream. Either way the three buckets tile the generation window - // and only the settlement tail stays unattributed. The split is - // priced ONLY when the window was: an unstamped call's model time + // spans and counts in the slot (its last block closes HERE, at the + // message); a V2+ log has no chunk events, so both come off the + // embedded stream. Either way the three buckets tile the generation + // window and only the settlement tail stays unattributed. The split + // is priced ONLY when the window was: an unstamped call's model time // is unattributed wholesale, so its spans must not reappear as // generation time the caller never charged. if (stepStart.decode !== undefined) { @@ -1306,10 +1326,10 @@ export function applyTimeline(state: TimelineState, event: TimelineEvent, bounds if (stepStart.block !== undefined) { decode[stepStart.block.kind] += durOf(stepStart.block.since, event.time) } - for (const kind of DECODE_KINDS) addDecode(timing, kind, decode[kind]) + for (const kind of DECODE_KINDS) addDecode(timing, kind, decode[kind], stepStart.blocks?.[kind] ?? 0) } else { - const spans = decodeSpansOfStream(data?.stream, event.time) - for (const kind of DECODE_KINDS) addDecode(timing, kind, spans[kind]) + const tally = decodeTallyOfStream(data?.stream, event.time) + for (const kind of DECODE_KINDS) addDecode(timing, kind, tally.spans[kind], tally.blocks[kind]) } } } diff --git a/src/host/logShapes.ts b/src/host/logShapes.ts index 3496ed7..a1a5983 100644 --- a/src/host/logShapes.ts +++ b/src/host/logShapes.ts @@ -56,21 +56,32 @@ export function decodeKindOfBlock(blockType: unknown): DecodeKind | undefined { return undefined } -/** Per-kind decode spans (see {@link decodeSpansOfStream}). */ +/** Per-kind decode spans (see {@link decodeTallyOfStream}). */ export type DecodeSpans = Record +/** Per-kind count of opened decode blocks (see {@link decodeTallyOfStream}). */ +export type DecodeCounts = Record + +/** Both decode tallies of one stream: the spans that price the split and the marker counts that qualify its rows. */ +export interface DecodeTally { + spans: DecodeSpans + blocks: DecodeCounts +} + /** - * Per-kind decode spans inside one embedded assistant stream, tiling - * [first block-start, endTime]: each `block-start` record owns the interval up - * to the next one, the last one up to `endTime`. This is the V2+ shape, whose - * timed stream rides the settlement (`assistant/message.data.stream`) instead - * of separate `assistant/chunk` events. Total over untrusted input — a - * malformed record is skipped, a non-finite boundary yields zero, and a stream - * with no marker (or not an array) yields all zeros. + * Per-kind decode spans AND counted `block-start` markers inside one embedded + * assistant stream, tiling [first block-start, endTime]: each `block-start` + * record owns the interval up to the next one, the last one up to `endTime`. + * This is the V2+ shape, whose timed stream rides the settlement + * (`assistant/message.data.stream`) instead of separate `assistant/chunk` + * events. Total over untrusted input — a malformed record is skipped whole (a + * marker with an unusable time anchors no span and counts nothing), a + * non-finite boundary yields zero, and a stream with no marker (or not an + * array) yields all zeros. */ -export function decodeSpansOfStream(stream: unknown, endTime: number): DecodeSpans { - const spans: DecodeSpans = { reasoning: 0, text: 0, toolarg: 0 } - if (!Array.isArray(stream) || !Number.isFinite(endTime)) return spans +export function decodeTallyOfStream(stream: unknown, endTime: number): DecodeTally { + const tally: DecodeTally = { spans: { reasoning: 0, text: 0, toolarg: 0 }, blocks: { reasoning: 0, text: 0, toolarg: 0 } } + if (!Array.isArray(stream) || !Number.isFinite(endTime)) return tally let kind: DecodeKind | undefined let since = 0 for (const record of stream) { @@ -81,12 +92,13 @@ export function decodeSpansOfStream(stream: unknown, endTime: number): DecodeSpa if (chunk.type !== 'block-start') continue const time = r.time if (typeof time !== 'number' || !Number.isFinite(time)) continue - if (kind !== undefined) spans[kind] += Math.max(0, time - since) + if (kind !== undefined) tally.spans[kind] += Math.max(0, time - since) kind = decodeKindOfBlock(chunk.blockType) + if (kind !== undefined) tally.blocks[kind] += 1 since = time } - if (kind !== undefined) spans[kind] += Math.max(0, endTime - since) - return spans + if (kind !== undefined) tally.spans[kind] += Math.max(0, endTime - since) + return tally } /** diff --git a/src/host/timeline.ts b/src/host/timeline.ts index a773a23..6b0e014 100644 --- a/src/host/timeline.ts +++ b/src/host/timeline.ts @@ -150,10 +150,14 @@ const timingTotalsSchema = z.object({ ttftMs: z.number().nonnegative(), genMs: z.number().nonnegative(), // Additive-optional (see TimingTotals): rows cached before the generation - // split carry `genMs` without these, and must keep parsing. + // split carry `genMs` without these, and must keep parsing. The block counts + // are additive-optional the same way (rows cached before they existed). reasoningMs: z.number().nonnegative().optional(), + reasoningBlocks: z.number().int().nonnegative().optional(), textMs: z.number().nonnegative().optional(), + textBlocks: z.number().int().nonnegative().optional(), toolArgMs: z.number().nonnegative().optional(), + toolArgBlocks: z.number().int().nonnegative().optional(), // The throughput seat, additive-optional for the same reason. speedTokens: z.number().nonnegative().optional(), speedMs: z.number().nonnegative().optional(), @@ -256,8 +260,10 @@ const timelineStateSchema = z.object({ stepStart: z.object({ time: z.number(), firstToken: z.number().optional(), - // The generation split's in-flight accumulator (see TimelineState.stepStart). + // The generation split's in-flight accumulator (see TimelineState.stepStart), + // with the opened blocks counted per bucket. decode: z.object({ reasoning: z.number(), text: z.number(), toolarg: z.number() }).strict().optional(), + blocks: z.object({ reasoning: z.number().int(), text: z.number().int(), toolarg: z.number().int() }).strict().optional(), block: z.object({ kind: z.enum(['reasoning', 'text', 'toolarg']), since: z.number() }).strict().optional(), }).strict().optional(), callNames: z.record(z.string(), z.object({ name: z.string(), start: z.number(), argsRaw: z.string().optional() }).strict()), diff --git a/src/shared/types.ts b/src/shared/types.ts index 9c4111a..d5769bd 100644 --- a/src/shared/types.ts +++ b/src/shared/types.ts @@ -492,10 +492,22 @@ export interface TimingTotals { genMs: number /** Reasoning-decode slice of `genMs` (the model's thinking). */ reasoningMs?: number + /** Counted reasoning-decode blocks (the Thinking slice's tally). */ + reasoningBlocks?: number /** Answer-text decode slice of `genMs`. */ textMs?: number + /** Counted answer-text decode blocks (the Answer slice's tally). */ + textBlocks?: number /** Tool-call-argument decode slice of `genMs`. */ toolArgMs?: number + /** + * Counted tool-call-argument decode blocks — one per tool call whose + * arguments the stream decoded (the Tool args slice's tally). The counts are + * ADDITIVE-OPTIONAL like their spans: a row cached before they existed (or a + * call whose stream framed no blocks) carries none, and the card qualifies + * only what was actually counted. + */ + toolArgBlocks?: number /** * The decode-throughput seat, paired exactly as the harness's own * session-stats fold pairs them: `speedTokens` sums provider-reported diff --git a/tests/client/components/statsTiming.spec.ts b/tests/client/components/statsTiming.spec.ts index 6d60f5e..651e4e6 100644 --- a/tests/client/components/statsTiming.spec.ts +++ b/tests/client/components/statsTiming.spec.ts @@ -155,6 +155,26 @@ describe('StatsTiming — the generation split', () => { await m.unmount() }) + test('the decode rows qualify with their OWN block tallies when the host folded them', async () => { + const timing: TimingTotals = { ...SPLIT, reasoningBlocks: 14, textBlocks: 5, toolArgBlocks: 26 } + const m = await mount(h(StatsTiming, { timing })) + assert.deepEqual(rowOf(m.container, 1), { pct: '15.0%', label: 'Thinking', count: '1m30s · 14 blocks', dim: false }) + assert.deepEqual(rowOf(m.container, 2), { pct: '5.0%', label: 'Answer', count: '30.0s · 5 blocks', dim: false }) + assert.deepEqual(rowOf(m.container, 3), { pct: '3.3%', label: 'Tool args', count: '20.0s · 26 blocks', dim: false }) + await m.unmount() + }) + + test('a zero or absent block tally renders the duration alone; the count localizes', async () => { + const zh = await mount(h(StatsTimingZh, { timing: { ...SPLIT, reasoningBlocks: 3 } })) + assert.equal(rowOf(zh.container, 1).count, '1m30s · 3次') + await zh.unmount() + for (const counts of [{ reasoningBlocks: 0 }, {}]) { + const m = await mount(h(StatsTiming, { timing: { ...SPLIT, ...counts } })) + assert.equal(rowOf(m.container, 1).count, '1m30s', JSON.stringify(counts)) + await m.unmount() + } + }) + test('the split labels localize', async () => { const m = await mount(h(StatsTimingZh, { timing: SPLIT })) assert.equal(rowOf(m.container, 1).label, '模型思考') diff --git a/tests/client/services.spec.ts b/tests/client/services.spec.ts index 74ea05a..9dbb477 100644 --- a/tests/client/services.spec.ts +++ b/tests/client/services.spec.ts @@ -516,6 +516,26 @@ describe('timingOf', () => { assert.equal(out?.reasoningMs, undefined) assert.equal(out?.wallMs, wellFormed.wallMs) }) + + test('the block counts pass through when well-formed and stay absent otherwise', () => { + const out = timingOf({ ...wellFormed, reasoningBlocks: 3, textBlocks: 1, toolArgBlocks: 9 }) + assert.deepEqual(out, { ...wellFormed, reasoningBlocks: 3, textBlocks: 1, toolArgBlocks: 9 }) + const bare = timingOf(wellFormed) + assert.ok(bare !== null) + for (const k of ['reasoningBlocks', 'textBlocks', 'toolArgBlocks']) { + assert.equal(Object.hasOwn(bare, k), false, `${k} stays absent`) + } + }) + + test('a wrong-typed or negative count drops alone; a non-finite one cannot slip through', () => { + const out = timingOf({ ...wellFormed, reasoningBlocks: 'x', textBlocks: -1, toolArgBlocks: 4 }) + assert.equal(out?.reasoningBlocks, undefined) + assert.equal(out?.textBlocks, undefined) + assert.equal(out?.toolArgBlocks, 4) + const out2 = timingOf({ ...wellFormed, textBlocks: Number.NaN }) + assert.equal(out2?.textBlocks, undefined) + assert.equal(out2?.wallMs, wellFormed.wallMs) + }) }) describe('timelineOf — the live system-prompt nodes', () => { diff --git a/tests/host/fold-timing.spec.ts b/tests/host/fold-timing.spec.ts index 46ebc94..710aa81 100644 --- a/tests/host/fold-timing.spec.ts +++ b/tests/host/fold-timing.spec.ts @@ -289,6 +289,10 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assert.equal(state.timing?.reasoningMs, 500, 'reasoning owns 200→700') assert.equal(state.timing?.textMs, 500, 'text owns 700→1200') assert.equal(state.timing?.toolArgMs, 800, 'tool args own 1200→message') + // Each marker is one counted block — the card's per-slice tally. + assert.equal(state.timing?.reasoningBlocks, 1) + assert.equal(state.timing?.textBlocks, 1) + assert.equal(state.timing?.toolArgBlocks, 1) }) test('V0: the buckets tile the marker span (they account for the generation window)', () => { @@ -307,7 +311,8 @@ describe('timing — the generation split (reasoning / text / tool args)', () => test('an unstamped call carries no split (its model time is unattributed wholesale)', () => { // Block markers but no token delta: the call prices no generation time, - // so its spans must not reappear as generation the caller never charged. + // so its spans must not reappear as generation the caller never charged — + // and its blocks count nothing either (the tally rides the same gate). const { state } = driveTimeline([ stepStart(1, { time: 0 }), blockStart(2, 'reasoning', 100), @@ -317,6 +322,8 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assert.equal(state.timing?.genMs, 0) assert.equal(state.timing?.reasoningMs, undefined) assert.equal(state.timing?.textMs, undefined) + assert.equal(state.timing?.reasoningBlocks, undefined) + assert.equal(state.timing?.textBlocks, undefined) }) test('V0: an unknown block marker closes the open block but opens nothing', () => { @@ -330,6 +337,8 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assert.equal(state.timing?.reasoningMs, 400, 'the reasoning span ends at the unknown marker') assert.equal(state.timing?.textMs, undefined) assert.equal(state.timing?.toolArgMs, undefined) + assert.equal(state.timing?.reasoningBlocks, 1, 'the unknown marker itself counted nothing') + assert.equal(state.timing?.textBlocks, undefined) }) test('V0: a marker before any open block starts a span; hostile times clamp', () => { @@ -341,11 +350,31 @@ describe('timing — the generation split (reasoning / text / tool args)', () => // A non-finite marker time poisons only its OWN span: the reasoning // block closes to a zero span and the text block it opens can never be // priced — both stay absent rather than reporting a bogus duration. + // No token delta ever stamps the call, so the split (spans AND counts) + // stays unattributed wholesale. assistantChunk(4, { type: 'block-start', index: 0, blockType: 'text' }, { time: Number.NaN }), assistantMessage(5, { time: 900 }), ]) assert.equal(state.timing?.reasoningMs, undefined) assert.equal(state.timing?.textMs, undefined) + assert.equal(state.timing?.reasoningBlocks, undefined) + assert.equal(state.timing?.textBlocks, undefined) + }) + + test('V0: a zero-span block still counts its marker (the tally needs no time)', () => { + const { state } = driveTimeline([ + stepStart(1, { time: 0 }), + assistantChunk(2, { type: 'text-delta', text: 'x' }, { time: 100 }), + blockStart(3, 'reasoning', 200), + // The text marker's unusable time prices no span, but the block opened. + assistantChunk(4, { type: 'block-start', index: 0, blockType: 'text' }, { time: Number.NaN }), + assistantMessage(5, { time: 900 }), + ]) + assert.equal(state.timing?.genMs, 800) + assert.equal(state.timing?.reasoningMs, undefined) + assert.equal(state.timing?.textMs, undefined) + assert.equal(state.timing?.reasoningBlocks, 1) + assert.equal(state.timing?.textBlocks, 1) }) test('a chunk with no open step stays uninteresting for the split too', () => { @@ -374,6 +403,10 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assert.equal(state.timing?.reasoningMs, 500) assert.equal(state.timing?.textMs, 500) assert.equal(state.timing?.toolArgMs, 800) + // The embedded stream's markers count too — one block per bucket here. + assert.equal(state.timing?.reasoningBlocks, 1) + assert.equal(state.timing?.textBlocks, 1) + assert.equal(state.timing?.toolArgBlocks, 1) }) test('a stream with no block marker contributes no split (the card keeps the un-split shape)', () => { @@ -388,6 +421,7 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assert.equal(state.timing?.reasoningMs, undefined) assert.equal(state.timing?.textMs, undefined) assert.equal(state.timing?.toolArgMs, undefined) + assert.equal(state.timing?.textBlocks, undefined) }) test('split totals accumulate across steps and stay plain JSON', () => { @@ -406,9 +440,27 @@ describe('timing — the generation split (reasoning / text / tool args)', () => ]) assert.equal(drive.state.timing?.reasoningMs, 200 + 300) assert.equal(drive.state.timing?.textMs, 200) + assert.equal(drive.state.timing?.reasoningBlocks, 2) + assert.equal(drive.state.timing?.textBlocks, 1) assertPlainJson(drive.state) }) + test('a slot cached before the block tally existed merges its spans without counts', () => { + // Rows cached by the previous build can hold a stamped slot with decode + // spans but no `blocks` record (additive-optional, see TimelineState): + // the merge reads it as no tallies. + const { def, state } = driveTimeline([ + stepStart(1, { time: 0 }), + assistantChunk(2, { type: 'reasoning-delta', text: 'x' }, { time: 100 }), + assistantChunk(3, { type: 'block-start', blockType: 'reasoning' }, { time: 100 }), + ]) + const stale = structuredClone(state) + if (stale.stepStart !== undefined) delete stale.stepStart.blocks + const merged = def.apply(stale, assistantMessage(4, { time: 400 })) + assert.equal(merged.timing?.reasoningMs, 300) + assert.equal(merged.timing?.reasoningBlocks, undefined) + }) + test('the generation split rides the wire view as plain values', () => { const drive = driveTimeline([ stepStart(1, { time: 0 }), @@ -417,6 +469,7 @@ describe('timing — the generation split (reasoning / text / tool args)', () => assistantMessage(4, { time: 400 }), ]) assert.equal(drive.view.timing?.reasoningMs, 300) + assert.equal(drive.view.timing?.reasoningBlocks, 1) }) }) @@ -443,10 +496,17 @@ describe('timing — served wire view', () => { const drive = driveTimeline([...step(1, 0, 1_000, { tokenMs: 300 }), toolCall(5, { callId: 'c1', name: 'bash' }), toolResult(6, { callId: 'c1', content: text('ok') }), - stepEnd(7, { time: 30_000 })]) + stepEnd(7, { time: 30_000 }), + // A step left OPEN with counted block markers in the slot: the final + // state carries stepStart.{decode,blocks,block} for the gate. + stepStart(8, { time: 40_000 }), + assistantChunk(9, { type: 'reasoning-delta', text: 'x' }, { time: 40_100 }), + assistantChunk(10, { type: 'block-start', blockType: 'reasoning' }, { time: 40_100 }), + assistantChunk(11, { type: 'block-start', blockType: 'text' }, { time: 40_300 })]) // The 0.1.1+ contract validates persisted state through stateSchema. const c = def as unknown as { stateSchema: { parse(s: unknown): unknown } } for (const state of drive.states) c.stateSchema.parse(structuredClone(state)) // throws on drift + assert.ok(drive.state.stepStart?.blocks !== undefined, 'the open slot carried the counted markers') }) }) diff --git a/tests/host/logShapes.spec.ts b/tests/host/logShapes.spec.ts index 159a9d0..0d48aa3 100644 --- a/tests/host/logShapes.spec.ts +++ b/tests/host/logShapes.spec.ts @@ -7,7 +7,7 @@ import assert from 'node:assert/strict' import { describe, test } from 'vitest' -import { decodeKindOfBlock, decodeSpansOfStream, firstTokenTimeOfStream, isTokenChunk, replaceRangeOf } from '../../src/host/logShapes' +import { decodeKindOfBlock, decodeTallyOfStream, firstTokenTimeOfStream, isTokenChunk, replaceRangeOf } from '../../src/host/logShapes' describe('decodeKindOfBlock', () => { test('maps the three block kinds the harness emits', () => { @@ -23,52 +23,71 @@ describe('decodeKindOfBlock', () => { }) }) -describe('decodeSpansOfStream', () => { +describe('decodeTallyOfStream', () => { const chunk = (time: number, blockType: string) => ({ type: 'chunk', time, chunk: { type: 'block-start', blockType } }) + const tally = { reasoning: 0, text: 0, toolarg: 0 } - test('tiles [first marker, endTime] by block, in marker order', () => { + test('tiles [first marker, endTime] by block, in marker order, counting each marker', () => { // reasoning 1000→1300, text 1300→1500, tool args 1500→2000 (endTime). - assert.deepEqual(decodeSpansOfStream([ + assert.deepEqual(decodeTallyOfStream([ chunk(1000, 'reasoning'), { type: 'reasoning-chunks', time0: 1010, index: 0, dt: [], texts: ['think'] }, chunk(1300, 'text'), { type: 'text-chunks', time0: 1310, index: 1, dt: [], texts: ['answer'] }, chunk(1500, 'tool-call'), { type: 'tool-call-chunks', time0: 1510, index: 2, dt: [], id: 'c1', args: ['{}'] }, - ], 2000), { reasoning: 300, text: 200, toolarg: 500 }) + ], 2000), { + spans: { reasoning: 300, text: 200, toolarg: 500 }, + blocks: { reasoning: 1, text: 1, toolarg: 1 }, + }) }) test('a later block closes the previous one even when its own kind is unknown', () => { - // The unknown marker still ends the reasoning span; its own interval is lost. - assert.deepEqual(decodeSpansOfStream([chunk(1000, 'reasoning'), chunk(1400, 'image')], 1900), { - reasoning: 400, text: 0, toolarg: 0, + // The unknown marker still ends the reasoning span; its own interval is + // lost and it counts nothing. + assert.deepEqual(decodeTallyOfStream([chunk(1000, 'reasoning'), chunk(1400, 'image')], 1900), { + spans: { reasoning: 400, text: 0, toolarg: 0 }, + blocks: { reasoning: 1, text: 0, toolarg: 0 }, }) }) test('a single block owns the whole tail to endTime', () => { - assert.deepEqual(decodeSpansOfStream([chunk(500, 'text')], 900), { reasoning: 0, text: 400, toolarg: 0 }) + assert.deepEqual(decodeTallyOfStream([chunk(500, 'text')], 900), { + spans: { ...tally, text: 400 }, + blocks: { ...tally, text: 1 }, + }) + }) + + test('a zero-span block still counts (same-instant markers)', () => { + assert.deepEqual(decodeTallyOfStream([chunk(500, 'reasoning'), chunk(500, 'text')], 900), { + spans: { ...tally, text: 400 }, + blocks: { reasoning: 1, text: 1, toolarg: 0 }, + }) }) test('malformed records, non-finite times, and hostile containers degrade to zero', () => { - assert.deepEqual(decodeSpansOfStream(undefined, 100), { reasoning: 0, text: 0, toolarg: 0 }) - assert.deepEqual(decodeSpansOfStream('stream', 100), { reasoning: 0, text: 0, toolarg: 0 }) - assert.deepEqual(decodeSpansOfStream([], 100), { reasoning: 0, text: 0, toolarg: 0 }) - assert.deepEqual(decodeSpansOfStream([chunk(500, 'text')], Number.NaN), { reasoning: 0, text: 0, toolarg: 0 }) - assert.deepEqual(decodeSpansOfStream([ + const zero = { spans: tally, blocks: tally } + assert.deepEqual(decodeTallyOfStream(undefined, 100), zero) + assert.deepEqual(decodeTallyOfStream('stream', 100), zero) + assert.deepEqual(decodeTallyOfStream([], 100), zero) + assert.deepEqual(decodeTallyOfStream([chunk(500, 'text')], Number.NaN), zero) + assert.deepEqual(decodeTallyOfStream([ null, 7, 'x', { type: 'chunk' }, { type: 'chunk', time: 1, chunk: null }, { type: 'chunk', time: 2, chunk: { type: 'text-delta', text: 'x' } }, + // The unusable time skips the record WHOLE: no span, no count. { type: 'chunk', time: 'x', chunk: { type: 'block-start', blockType: 'text' } }, { type: 'text-chunks', time0: 1, index: 0, dt: [], texts: ['a'] }, - ], 100), { reasoning: 0, text: 0, toolarg: 0 }) + ], 100), zero) }) test('a backwards marker clamps to a zero span instead of a negative one', () => { // The text block's interval is negative → 0; the reasoning block is last, // so it owns the tail to endTime. - assert.deepEqual(decodeSpansOfStream([chunk(1000, 'text'), chunk(900, 'reasoning')], 950), { - reasoning: 50, text: 0, toolarg: 0, + assert.deepEqual(decodeTallyOfStream([chunk(1000, 'text'), chunk(900, 'reasoning')], 950), { + spans: { reasoning: 50, text: 0, toolarg: 0 }, + blocks: { reasoning: 1, text: 1, toolarg: 0 }, }) }) })