feat(timing): tally the decode slices' counted blocks on the timing card

The generation split (thinking / answer / tool args) already tiles its
window off the stream's block-start markers; the same markers now count
into additive-optional per-bucket tallies (reasoningBlocks / textBlocks /
toolArgBlocks), so the card qualifies each decode slice with the number
of blocks actually decoded - the honest per-slice counterpart of TTFT's
call count and tools' run count (one model call emits zero to many
blocks, so a call count there would be a false tally). Overhead stays
unqualified: it is the residue, with nothing behind it to count.

Both log generations carry the markers: the V0 chunk flood counts them
into the step slot alongside the spans, and the V2+ embedded stream
yields them from the same single pass that prices the split
(decodeSpansOfStream -> decodeTallyOfStream). Counts ride the split's
own first-token gate, and rows cached before the fields existed render
the duration alone.
This commit is contained in:
bowenliang123 committed 2026-09-23 13:11:39 +08:00
1 parent 6064731c9f
commit f723cddb30
11 files changed
+273 -91

No files matched your search

+21 -15
View File
@@ -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 })
}
+2 -2
View File
@@ -41,7 +41,7 @@ export const DICT_ZH: Record<string, string> = {
'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<string, string> = {
'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.',
+21 -14
View File
@@ -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
}
+45 -25
View File
@@ -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<DecodeKind, number>; block?: { kind: DecodeKind; since: number } }
stepStart?: {
time: number
firstToken?: number
decode?: Record<DecodeKind, number>
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<DecodeKind, { ms: 'reasoningMs' | 'textMs' | 'toolArgMs'; n: 'reasoningBlocks' | 'textBlocks' | 'toolArgBlocks' }> = {
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])
}
}
}
+26 -14
View File
@@ -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<DecodeKind, number>
/** Per-kind count of opened decode blocks (see {@link decodeTallyOfStream}). */
export type DecodeCounts = Record<DecodeKind, number>
/** 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
}
/**
+8 -2
View File
@@ -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()),
+12
View File
@@ -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
@@ -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, '模型思考')
+20
View File
@@ -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', () => {
+62 -2
View File
@@ -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')
})
})
+36 -17
View File
@@ -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 },
})
})
})