mirror of
https://github.com/NanmiCoder/claude-code-haha.git
synced 2026-10-10 03:43:11 +08:00
feat(usage): show session token totals and generation speed in the context panel
The context panel could say what was in the window but nothing about what the session had spent: no total token count, no cache hit rate, no generation speed. The numbers were already on the wire — translateCliUsage picked four token buckets out of the CLI's result message and dropped duration_ms, duration_api_ms and num_turns with them — and nothing anywhere accumulated how long the model spent emitting tokens rather than waiting on prefill. Measure that span where it happens: a decode span opens at the first generated delta and closes at message_stop, rides the stream_event up to QueryEngine, and accumulates in cost-tracker beside totalAPIDuration, including the project config restore path so it survives a CLI restart. Tokens/sec is output over that span, never over wall clock, which would divide by tool execution time. The totals needed fixing before they were worth showing. Claude Code persists one JSONL line per content block of a reply and repeats the whole usage object on every one, so summing lines overstated real transcripts by 2.2x — and chooseRicherUsage prefers the larger of two snapshots, so the inspector actively selected the inflated one. The transcript readers and the renderer's history summary now deduplicate on usageAccounting's key, the rule stats.ts and the activity index already use. The panel polls a usageOnly inspection mode while it is open and stops when it closes: one get_session_usage control, no skills-directory scan, no transcript re-read, and no request stacked behind one that has not answered.
This commit is contained in:
@@ -167,6 +167,14 @@ export type SessionUsageSnapshot = {
|
||||
costDisplay: string
|
||||
hasUnknownModelCost: boolean
|
||||
totalAPIDuration: number
|
||||
/**
|
||||
* Milliseconds the model spent emitting tokens, excluding prefill and tool execution.
|
||||
* Absent or 0 means unknown (transcript source, aborted turn, non-streaming fallback) —
|
||||
* never "instant", so a tokens/sec reading must be withheld rather than computed.
|
||||
*/
|
||||
totalDecodeDuration?: number
|
||||
/** Milliseconds spent waiting for the first token, summed over the session's requests. */
|
||||
totalTtftDuration?: number
|
||||
totalDuration: number
|
||||
totalLinesAdded: number
|
||||
totalLinesRemoved: number
|
||||
@@ -479,6 +487,17 @@ export const sessionsApi = {
|
||||
})
|
||||
},
|
||||
|
||||
/**
|
||||
* Running session totals only — one CLI control, no skills scan, no transcript re-read.
|
||||
* Cheap enough to poll while the context panel is open.
|
||||
*/
|
||||
getSessionUsage(sessionId: string, signal?: AbortSignal) {
|
||||
return api.get<SessionInspectionResponse>(
|
||||
`/api/sessions/${sessionId}/inspection?includeContext=0&usageOnly=1`,
|
||||
{ timeout: 6_000, signal },
|
||||
)
|
||||
},
|
||||
|
||||
getWorkspaceStatus(sessionId: string, signal?: AbortSignal) {
|
||||
return api.get<WorkspaceStatusResult>(buildWorkspacePath(sessionId, 'status'), { signal })
|
||||
},
|
||||
|
||||
@@ -1,8 +1,27 @@
|
||||
import { formatDurationMs } from '../../lib/trace/formatters'
|
||||
import {
|
||||
formatCacheHitRate,
|
||||
formatCompactTokens,
|
||||
formatTokensPerSecond,
|
||||
} from '../../lib/sessionUsageMetrics'
|
||||
|
||||
type ContextCategory = {
|
||||
name: string
|
||||
tokens: number
|
||||
}
|
||||
|
||||
/**
|
||||
* Lifetime figures for the whole session, as opposed to `categories` which describe only what
|
||||
* currently occupies the context window. Kept as raw numbers so the formatting rules (never
|
||||
* rounding a cache hit up to 100%, withholding a speed with no decode span) stay in one place.
|
||||
*/
|
||||
export type ContextUsageSessionStats = {
|
||||
totalTokens: number
|
||||
cacheHitRate: number | null
|
||||
tokensPerSecond: number | null
|
||||
apiDurationMs: number
|
||||
}
|
||||
|
||||
export type ContextUsageDetailsStatus = 'ready' | 'pending' | 'loading' | 'unavailable'
|
||||
|
||||
export type ContextUsageDetailsProps = {
|
||||
@@ -13,6 +32,7 @@ export type ContextUsageDetailsProps = {
|
||||
freeTokens: number
|
||||
maxTokens: number
|
||||
categories: ContextCategory[]
|
||||
sessionStats?: ContextUsageSessionStats | null
|
||||
updatedAtLabel?: string
|
||||
estimate?: boolean
|
||||
status: ContextUsageDetailsStatus
|
||||
@@ -25,6 +45,13 @@ export type ContextUsageDetailsProps = {
|
||||
pendingDetail: string
|
||||
loading: string
|
||||
unavailableDetail: string
|
||||
sessionUsage: string
|
||||
sessionTotalTokens: string
|
||||
sessionCacheHit: string
|
||||
sessionSpeed: string
|
||||
sessionApiDuration: string
|
||||
sessionSpeedUnit: string
|
||||
sessionScopeNote: string
|
||||
}
|
||||
}
|
||||
|
||||
@@ -32,6 +59,71 @@ function formatNumber(value: number) {
|
||||
return new Intl.NumberFormat().format(value)
|
||||
}
|
||||
|
||||
/**
|
||||
* Lifetime session totals. Rendered below the window breakdown because the two answer different
|
||||
* questions: the bars say what is in the context right now, this says what the session has spent.
|
||||
*/
|
||||
function SessionUsage({
|
||||
stats,
|
||||
labels,
|
||||
density,
|
||||
}: {
|
||||
stats: ContextUsageSessionStats
|
||||
labels: ContextUsageDetailsProps['labels']
|
||||
density: 'compact' | 'comfortable'
|
||||
}) {
|
||||
const labelClass = density === 'compact'
|
||||
? 'text-[12.5px] text-[var(--color-text-tertiary)]'
|
||||
: 'text-xs text-[var(--color-text-tertiary)]'
|
||||
const valueClass = 'font-mono text-sm text-[var(--color-text-primary)]'
|
||||
|
||||
return (
|
||||
<div className="mt-4 border-t border-[var(--color-border)] pt-3">
|
||||
<div className={labelClass}>{labels.sessionUsage}</div>
|
||||
|
||||
<div className="mt-2 flex items-baseline justify-between gap-3">
|
||||
<span className="text-[13.5px] text-[var(--color-text-primary)]">{labels.sessionTotalTokens}</span>
|
||||
<span
|
||||
className="shrink-0 font-mono text-[15px] font-semibold text-[var(--color-text-primary)]"
|
||||
title={formatNumber(stats.totalTokens)}
|
||||
data-testid="session-total-tokens"
|
||||
>
|
||||
{formatCompactTokens(stats.totalTokens)}
|
||||
</span>
|
||||
</div>
|
||||
|
||||
<div className="mt-3 grid grid-cols-2 gap-3">
|
||||
<div>
|
||||
<div className={labelClass}>{labels.sessionCacheHit}</div>
|
||||
<div className={`mt-[3px] ${valueClass}`} data-testid="session-cache-hit">
|
||||
{stats.cacheHitRate === null ? '--' : formatCacheHitRate(stats.cacheHitRate)}
|
||||
</div>
|
||||
</div>
|
||||
<div>
|
||||
<div className={labelClass}>{labels.sessionSpeed}</div>
|
||||
<div className={`mt-[3px] ${valueClass}`} data-testid="session-speed">
|
||||
{formatTokensPerSecond(stats.tokensPerSecond ?? 0)}
|
||||
{stats.tokensPerSecond !== null && (
|
||||
<span className="ml-1 text-[11px] text-[var(--color-text-tertiary)]">{labels.sessionSpeedUnit}</span>
|
||||
)}
|
||||
</div>
|
||||
</div>
|
||||
</div>
|
||||
|
||||
<div className="mt-3 flex items-baseline justify-between gap-3">
|
||||
<span className="text-[13.5px] text-[var(--color-text-primary)]">{labels.sessionApiDuration}</span>
|
||||
<span className="shrink-0 font-mono text-[13px] text-[var(--color-text-secondary)]">
|
||||
{formatDurationMs(stats.apiDurationMs)}
|
||||
</span>
|
||||
</div>
|
||||
|
||||
{/* Subagent transcripts are separate files and are never folded in here; saying so beats
|
||||
letting the number quietly disagree with the user's bill. */}
|
||||
<div className="mt-2 text-[11px] text-[var(--color-text-tertiary)]">{labels.sessionScopeNote}</div>
|
||||
</div>
|
||||
)
|
||||
}
|
||||
|
||||
function CategoryBars({
|
||||
categories,
|
||||
maxTokens,
|
||||
@@ -81,6 +173,7 @@ export function ContextUsageDetails({
|
||||
freeTokens,
|
||||
maxTokens,
|
||||
categories,
|
||||
sessionStats,
|
||||
updatedAtLabel,
|
||||
estimate = false,
|
||||
status,
|
||||
@@ -120,11 +213,16 @@ export function ContextUsageDetails({
|
||||
</div>
|
||||
</div>
|
||||
<CategoryBars categories={categories} maxTokens={maxTokens} density="comfortable" />
|
||||
{/* Above the session block on purpose: this timestamp describes the window
|
||||
breakdown, which refreshes on a much slower cadence than the live totals. */}
|
||||
{updatedAtLabel && (
|
||||
<div className="mt-4 text-[11px] text-[var(--color-text-tertiary)]">
|
||||
{updatedAtLabel}
|
||||
</div>
|
||||
)}
|
||||
{sessionStats && (
|
||||
<SessionUsage stats={sessionStats} labels={labels} density="comfortable" />
|
||||
)}
|
||||
</div>
|
||||
) : (
|
||||
<div className="mt-5 rounded-[var(--radius-lg)] bg-[var(--color-surface-container)] p-4 text-sm leading-6 text-[var(--color-text-secondary)]">
|
||||
@@ -177,6 +275,8 @@ export function ContextUsageDetails({
|
||||
</div>
|
||||
</div>
|
||||
<CategoryBars categories={categories} maxTokens={maxTokens} density="compact" />
|
||||
{/* Above the session block on purpose: this timestamp describes the window
|
||||
breakdown, which refreshes on a much slower cadence than the live totals. */}
|
||||
{updatedAtLabel && (
|
||||
<div className="mt-4 text-xs text-[var(--color-text-tertiary)]">
|
||||
{updatedAtLabel}
|
||||
@@ -187,6 +287,9 @@ export function ContextUsageDetails({
|
||||
)}
|
||||
</div>
|
||||
)}
|
||||
{sessionStats && (
|
||||
<SessionUsage stats={sessionStats} labels={labels} density="compact" />
|
||||
)}
|
||||
</>
|
||||
) : status === 'pending' ? (
|
||||
<div className="mt-4 text-sm leading-6 text-[var(--color-text-secondary)]">
|
||||
|
||||
@@ -5,6 +5,10 @@ import '@testing-library/jest-dom'
|
||||
const { sessionsApiMock, runtimeMocks } = vi.hoisted(() => ({
|
||||
sessionsApiMock: {
|
||||
getInspection: vi.fn(),
|
||||
// Defaulted rather than bare: every test that opens the breakdown now starts the usage
|
||||
// poll, including the ones written before it existed that only care about the context
|
||||
// meter. `clearAllMocks` clears calls, not implementations, so this survives beforeEach.
|
||||
getSessionUsage: vi.fn(async () => ({ active: true, status: {} })),
|
||||
},
|
||||
runtimeMocks: {
|
||||
isMobileViewport: false,
|
||||
@@ -28,6 +32,7 @@ vi.mock('../../api/sessions', async (importOriginal) => {
|
||||
sessionsApi: {
|
||||
...actual.sessionsApi,
|
||||
getInspection: sessionsApiMock.getInspection,
|
||||
getSessionUsage: sessionsApiMock.getSessionUsage,
|
||||
},
|
||||
}
|
||||
})
|
||||
@@ -751,3 +756,201 @@ describe('ContextUsageIndicator presentation', () => {
|
||||
expect(screen.queryByTestId('context-usage-popover')).not.toBeInTheDocument()
|
||||
})
|
||||
})
|
||||
|
||||
describe('ContextUsageIndicator session usage', () => {
|
||||
const usageInspection = (usage: Record<string, unknown>) => ({
|
||||
active: true,
|
||||
status: baseInspection.status,
|
||||
context: baseInspection.context,
|
||||
usage,
|
||||
})
|
||||
|
||||
const baseUsage = {
|
||||
source: 'current_process' as const,
|
||||
totalCostUSD: 1.23,
|
||||
costDisplay: '$1.23',
|
||||
hasUnknownModelCost: false,
|
||||
totalAPIDuration: 42_000,
|
||||
totalDecodeDuration: 12_000,
|
||||
totalTtftDuration: 3_000,
|
||||
totalDuration: 300,
|
||||
totalLinesAdded: 0,
|
||||
totalLinesRemoved: 0,
|
||||
totalInputTokens: 1_000,
|
||||
totalOutputTokens: 2_400,
|
||||
totalCacheReadInputTokens: 9_000,
|
||||
totalCacheCreationInputTokens: 0,
|
||||
totalWebSearchRequests: 0,
|
||||
models: [],
|
||||
}
|
||||
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks()
|
||||
runtimeMocks.isMobileViewport = false
|
||||
runtimeMocks.isDesktopRuntime = false
|
||||
useSettingsStore.setState({ locale: 'en' })
|
||||
sessionsApiMock.getInspection.mockResolvedValue(baseInspection)
|
||||
sessionsApiMock.getSessionUsage.mockResolvedValue(usageInspection(baseUsage))
|
||||
})
|
||||
|
||||
afterEach(() => {
|
||||
cleanup()
|
||||
})
|
||||
|
||||
it('does not poll session usage while the breakdown is closed', async () => {
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
|
||||
await waitFor(() => {
|
||||
expect(screen.getByTestId('context-usage-indicator')).toHaveTextContent('21%')
|
||||
})
|
||||
|
||||
// The poll is a per-open cost. Fetching for a panel nobody opened would put a CLI control
|
||||
// round-trip on every session for no visible benefit.
|
||||
expect(sessionsApiMock.getSessionUsage).not.toHaveBeenCalled()
|
||||
})
|
||||
|
||||
it('renders lifetime totals once the breakdown opens', async () => {
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await waitFor(() => {
|
||||
expect(screen.getByTestId('context-usage-indicator')).toHaveTextContent('21%')
|
||||
})
|
||||
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
|
||||
// 1000 input + 9000 cache read + 2400 output; the cached tokens are counted once.
|
||||
expect(await screen.findByTestId('session-total-tokens')).toHaveTextContent('12.4K')
|
||||
expect(screen.getByTestId('session-cache-hit')).toHaveTextContent('90.0%')
|
||||
expect(screen.getByTestId('session-speed')).toHaveTextContent('200')
|
||||
expect(screen.getByTestId('session-speed')).toHaveTextContent('tok/s')
|
||||
expect(sessionsApiMock.getSessionUsage).toHaveBeenCalledWith('session-1', expect.anything())
|
||||
})
|
||||
|
||||
it('never reports a partial cache as a perfect one', async () => {
|
||||
sessionsApiMock.getSessionUsage.mockResolvedValue(usageInspection({
|
||||
...baseUsage,
|
||||
totalInputTokens: 4,
|
||||
totalCacheReadInputTokens: 9_996,
|
||||
}))
|
||||
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await waitFor(() => {
|
||||
expect(screen.getByTestId('context-usage-indicator')).toHaveTextContent('21%')
|
||||
})
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
|
||||
expect(await screen.findByTestId('session-cache-hit')).toHaveTextContent('99.96%')
|
||||
expect(screen.getByTestId('session-cache-hit')).not.toHaveTextContent('100%')
|
||||
})
|
||||
|
||||
it('withholds the speed reading when the session reported no decode span', async () => {
|
||||
// Transcript-sourced usage has no generation timing. Showing a number here would mean
|
||||
// dividing by wall clock, which includes tool execution.
|
||||
sessionsApiMock.getSessionUsage.mockResolvedValue(usageInspection({
|
||||
...baseUsage,
|
||||
totalDecodeDuration: 0,
|
||||
}))
|
||||
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await waitFor(() => {
|
||||
expect(screen.getByTestId('context-usage-indicator')).toHaveTextContent('21%')
|
||||
})
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
|
||||
expect(await screen.findByTestId('session-speed')).toHaveTextContent('--')
|
||||
expect(screen.getByTestId('session-speed')).not.toHaveTextContent('tok/s')
|
||||
})
|
||||
|
||||
it('hides the block entirely for a session that has spent nothing', async () => {
|
||||
sessionsApiMock.getSessionUsage.mockResolvedValue(usageInspection({
|
||||
...baseUsage,
|
||||
totalInputTokens: 0,
|
||||
totalOutputTokens: 0,
|
||||
totalCacheReadInputTokens: 0,
|
||||
totalDecodeDuration: 0,
|
||||
}))
|
||||
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await waitFor(() => {
|
||||
expect(screen.getByTestId('context-usage-indicator')).toHaveTextContent('21%')
|
||||
})
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
|
||||
await screen.findByTestId('context-usage-popover')
|
||||
// An all-zero row would read as a measurement rather than an absence.
|
||||
expect(screen.queryByTestId('session-total-tokens')).not.toBeInTheDocument()
|
||||
})
|
||||
|
||||
it('does not stack polls behind a request that has not answered yet', async () => {
|
||||
vi.useFakeTimers()
|
||||
try {
|
||||
// A stuck CLI control: the request never settles, so every tick would pile another
|
||||
// round-trip on top of it if the timer were the only gate.
|
||||
sessionsApiMock.getSessionUsage.mockImplementation(() => new Promise(() => {}))
|
||||
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0)
|
||||
})
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0)
|
||||
})
|
||||
|
||||
// Three poll intervals, including the one that fires while the first request is open.
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(9_000)
|
||||
})
|
||||
|
||||
expect(sessionsApiMock.getSessionUsage).toHaveBeenCalledTimes(1)
|
||||
} finally {
|
||||
vi.useRealTimers()
|
||||
}
|
||||
})
|
||||
|
||||
it('polls while open and stops when the panel closes', async () => {
|
||||
vi.useFakeTimers()
|
||||
try {
|
||||
render(
|
||||
<ContextUsageIndicator sessionId="session-1" chatState="idle" messageCount={1} />,
|
||||
)
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0)
|
||||
})
|
||||
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0)
|
||||
})
|
||||
expect(sessionsApiMock.getSessionUsage).toHaveBeenCalledTimes(1)
|
||||
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(6_000)
|
||||
})
|
||||
expect(sessionsApiMock.getSessionUsage.mock.calls.length).toBeGreaterThanOrEqual(3)
|
||||
|
||||
const callsWhileOpen = sessionsApiMock.getSessionUsage.mock.calls.length
|
||||
fireEvent.click(screen.getByTestId('context-usage-indicator'))
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(9_000)
|
||||
})
|
||||
|
||||
// Nothing keeps ticking after the popover is dismissed — the timer is owned by the
|
||||
// open state, not by the component's lifetime.
|
||||
expect(sessionsApiMock.getSessionUsage.mock.calls.length).toBe(callsWhileOpen)
|
||||
} finally {
|
||||
vi.useRealTimers()
|
||||
}
|
||||
})
|
||||
})
|
||||
|
||||
@@ -1,13 +1,22 @@
|
||||
import { useCallback, useEffect, useLayoutEffect, useMemo, useRef, useState } from 'react'
|
||||
import { createPortal } from 'react-dom'
|
||||
import { sessionsApi, type SessionContextSnapshot } from '../../api/sessions'
|
||||
import {
|
||||
sessionsApi,
|
||||
type SessionContextSnapshot,
|
||||
type SessionUsageSnapshot,
|
||||
} from '../../api/sessions'
|
||||
import { useTranslation } from '../../i18n'
|
||||
import type { ChatState } from '../../types/chat'
|
||||
import { useMobileViewport } from '../../hooks/useMobileViewport'
|
||||
import { useDismissable } from '../../hooks/useDismissable'
|
||||
import { isDesktopRuntime } from '../../lib/desktopRuntime'
|
||||
import { deriveSessionUsageMetrics } from '../../lib/sessionUsageMetrics'
|
||||
import { MobileBottomSheet } from '@/components/ui/MobileBottomSheet'
|
||||
import { ContextUsageDetails, type ContextUsageDetailsStatus } from './ContextUsageDetails'
|
||||
import {
|
||||
ContextUsageDetails,
|
||||
type ContextUsageDetailsStatus,
|
||||
type ContextUsageSessionStats,
|
||||
} from './ContextUsageDetails'
|
||||
|
||||
type Props = {
|
||||
sessionId?: string
|
||||
@@ -31,6 +40,11 @@ const ACTIVE_REFRESH_MS = 30_000
|
||||
// racing a client abort that can strand loopback sockets on Windows.
|
||||
const CONTEXT_REQUEST_TIMEOUT_MS = 30_000
|
||||
const AUTO_REFRESH_MIN_INTERVAL_MS = 10_000
|
||||
// Lifetime totals only change when a turn completes, but a turn can run for minutes and the
|
||||
// user is staring at the panel while it does. Polling is scoped to the open popover/sheet —
|
||||
// a closed panel costs nothing — and the request it makes is the single-control `usageOnly`
|
||||
// path, not the full inspection.
|
||||
const USAGE_POLL_MS = 3_000
|
||||
// Right after a completed turn, compaction, or runtime restart the CLI can
|
||||
// still be settling, so retry the event-driven refresh once.
|
||||
const FORCED_REFRESH_RETRY_MS = 5_000
|
||||
@@ -115,6 +129,8 @@ export function ContextUsageIndicator({
|
||||
const [error, setError] = useState<string | null>(null)
|
||||
const [updatedAt, setUpdatedAt] = useState<number | null>(null)
|
||||
const [inspectionModel, setInspectionModel] = useState<string | null>(null)
|
||||
const [usage, setUsage] = useState<SessionUsageSnapshot | null>(null)
|
||||
const usageSessionIdRef = useRef<string | undefined>(undefined)
|
||||
const [detailsOpen, setDetailsOpen] = useState(false)
|
||||
const [popoverPosition, setPopoverPosition] = useState<PopoverPosition | null>(null)
|
||||
const triggerRef = useRef<HTMLButtonElement>(null)
|
||||
@@ -308,6 +324,48 @@ export function ContextUsageIndicator({
|
||||
return () => clearInterval(timer)
|
||||
}, [chatState, messageCount, refresh])
|
||||
|
||||
// Lifetime session totals, polled only while the breakdown is on screen. The request is the
|
||||
// single-control `usageOnly` one, so a 3s cadence costs far less than the context refresh it
|
||||
// sits next to, and closing the panel takes the timer with it — nothing runs in the
|
||||
// background, and a hidden document skips its ticks rather than queueing them.
|
||||
useEffect(() => {
|
||||
if (!detailsOpen || !sessionId) return
|
||||
if (typeof sessionsApi.getSessionUsage !== 'function') return
|
||||
let cancelled = false
|
||||
// The poll interval is shorter than the request deadline, so a slow server would otherwise
|
||||
// let ticks stack up behind the in-flight one. Skipping a tick loses nothing: the answer
|
||||
// that is still outstanding is the same answer the new tick would have asked for.
|
||||
let inFlight = false
|
||||
const controller = new AbortController()
|
||||
|
||||
const load = () => {
|
||||
if (inFlight || !isDocumentVisible()) return
|
||||
inFlight = true
|
||||
void sessionsApi.getSessionUsage(sessionId, controller.signal)
|
||||
.then((inspection) => {
|
||||
if (cancelled || !inspection.usage) return
|
||||
usageSessionIdRef.current = sessionId
|
||||
setUsage(inspection.usage)
|
||||
})
|
||||
.catch(() => {
|
||||
// A failed poll (CLI busy, control timeout) leaves the last good numbers on screen.
|
||||
// The panel is a readout, not a task; a flickering error would be worse than a
|
||||
// value that is three seconds stale.
|
||||
})
|
||||
.finally(() => {
|
||||
inFlight = false
|
||||
})
|
||||
}
|
||||
|
||||
load()
|
||||
const timer = setInterval(load, USAGE_POLL_MS)
|
||||
return () => {
|
||||
cancelled = true
|
||||
controller.abort()
|
||||
clearInterval(timer)
|
||||
}
|
||||
}, [detailsOpen, sessionId])
|
||||
|
||||
// If the presentation mode flips (Workbench drag, H5 resize), drop any open
|
||||
// shell so we don't leave a desktop popover stranded on a sheet layout.
|
||||
useEffect(() => {
|
||||
@@ -369,8 +427,32 @@ export function ContextUsageIndicator({
|
||||
pendingDetail: t('contextIndicator.pendingDetail'),
|
||||
loading: t('contextIndicator.loading'),
|
||||
unavailableDetail: t('contextIndicator.unavailableDetail'),
|
||||
sessionUsage: t('contextIndicator.sessionUsage'),
|
||||
sessionTotalTokens: t('contextIndicator.sessionTotalTokens'),
|
||||
sessionCacheHit: t('contextIndicator.sessionCacheHit'),
|
||||
sessionSpeed: t('contextIndicator.sessionSpeed'),
|
||||
sessionApiDuration: t('contextIndicator.sessionApiDuration'),
|
||||
sessionSpeedUnit: t('contextIndicator.sessionSpeedUnit'),
|
||||
sessionScopeNote: t('contextIndicator.sessionScopeNote'),
|
||||
}), [t])
|
||||
|
||||
// Derived per render rather than memoized on `usage` alone: the session it belongs to lives in
|
||||
// a ref, so the guard has to run against the current sessionId every time.
|
||||
const displayUsage = usageSessionIdRef.current === sessionId ? usage : null
|
||||
const sessionStats = useMemo<ContextUsageSessionStats | null>(() => {
|
||||
if (!displayUsage) return null
|
||||
const metrics = deriveSessionUsageMetrics(displayUsage)
|
||||
// A session with nothing spent yet has no honest answer for any of these rows; showing an
|
||||
// empty block (or a 0 tok/s) would read as a measurement rather than an absence.
|
||||
if (metrics.totalTokens === 0) return null
|
||||
return {
|
||||
totalTokens: metrics.totalTokens,
|
||||
cacheHitRate: metrics.cacheHitRate,
|
||||
tokensPerSecond: metrics.tokensPerSecond,
|
||||
apiDurationMs: displayUsage.totalAPIDuration,
|
||||
}
|
||||
}, [displayUsage])
|
||||
|
||||
const detailsBody = (
|
||||
<ContextUsageDetails
|
||||
variant={preferSheet ? 'sheet' : 'popover'}
|
||||
@@ -380,6 +462,7 @@ export function ContextUsageIndicator({
|
||||
freeTokens={freeTokens}
|
||||
maxTokens={maxTokens}
|
||||
categories={details}
|
||||
sessionStats={sessionStats}
|
||||
updatedAtLabel={displayContext ? formatUpdatedAt(updatedAt, t) : undefined}
|
||||
estimate={contextSource === 'estimate'}
|
||||
status={detailsStatus}
|
||||
|
||||
@@ -2583,6 +2583,13 @@ Row 9, all 8 cells: continuing from straight down, turning left through lower-le
|
||||
'contextIndicator.updatedNow': 'Updated just now',
|
||||
'contextIndicator.updatedMinutes': 'Updated {count}m ago',
|
||||
'contextIndicator.estimate': 'Estimate',
|
||||
'contextIndicator.sessionUsage': 'This session',
|
||||
'contextIndicator.sessionTotalTokens': 'Total tokens',
|
||||
'contextIndicator.sessionCacheHit': 'Cache hit',
|
||||
'contextIndicator.sessionSpeed': 'Speed',
|
||||
'contextIndicator.sessionApiDuration': 'API time',
|
||||
'contextIndicator.sessionSpeedUnit': 'tok/s',
|
||||
'contextIndicator.sessionScopeNote': 'Subagents excluded',
|
||||
'chat.navigate': 'navigate',
|
||||
'chat.select': 'select',
|
||||
'chat.dismiss': 'dismiss',
|
||||
|
||||
@@ -2586,6 +2586,13 @@ export const jp: Record<TranslationKey, string> = {
|
||||
'contextIndicator.updatedNow': 'たった今更新',
|
||||
'contextIndicator.updatedMinutes': '{count} 分前に更新',
|
||||
'contextIndicator.estimate': '推定',
|
||||
'contextIndicator.sessionUsage': 'このセッション',
|
||||
'contextIndicator.sessionTotalTokens': '合計トークン',
|
||||
'contextIndicator.sessionCacheHit': 'キャッシュヒット',
|
||||
'contextIndicator.sessionSpeed': '生成速度',
|
||||
'contextIndicator.sessionApiDuration': 'API 時間',
|
||||
'contextIndicator.sessionSpeedUnit': 'tok/s',
|
||||
'contextIndicator.sessionScopeNote': 'サブエージェントを除く',
|
||||
'chat.navigate': '移動',
|
||||
'chat.select': '選択',
|
||||
'chat.dismiss': '閉じる',
|
||||
|
||||
@@ -2586,6 +2586,13 @@ export const kr: Record<TranslationKey, string> = {
|
||||
'contextIndicator.updatedNow': '방금 업데이트됨',
|
||||
'contextIndicator.updatedMinutes': '{count}분 전 업데이트됨',
|
||||
'contextIndicator.estimate': '추정',
|
||||
'contextIndicator.sessionUsage': '이 세션',
|
||||
'contextIndicator.sessionTotalTokens': '총 토큰',
|
||||
'contextIndicator.sessionCacheHit': '캐시 적중',
|
||||
'contextIndicator.sessionSpeed': '생성 속도',
|
||||
'contextIndicator.sessionApiDuration': 'API 시간',
|
||||
'contextIndicator.sessionSpeedUnit': 'tok/s',
|
||||
'contextIndicator.sessionScopeNote': '하위 에이전트 제외',
|
||||
'chat.navigate': '이동',
|
||||
'chat.select': '선택',
|
||||
'chat.dismiss': '닫기',
|
||||
|
||||
@@ -2585,6 +2585,13 @@ export const zh: Record<TranslationKey, string> = {
|
||||
'contextIndicator.updatedNow': '剛剛更新',
|
||||
'contextIndicator.updatedMinutes': '{count} 分鐘前更新',
|
||||
'contextIndicator.estimate': '估算',
|
||||
'contextIndicator.sessionUsage': '此次工作階段',
|
||||
'contextIndicator.sessionTotalTokens': '總 token',
|
||||
'contextIndicator.sessionCacheHit': '快取命中',
|
||||
'contextIndicator.sessionSpeed': '生成速度',
|
||||
'contextIndicator.sessionApiDuration': 'API 耗時',
|
||||
'contextIndicator.sessionSpeedUnit': 'tok/s',
|
||||
'contextIndicator.sessionScopeNote': '不含子代理用量',
|
||||
'chat.navigate': '導航',
|
||||
'chat.select': '選擇',
|
||||
'chat.dismiss': '關閉',
|
||||
|
||||
@@ -2584,6 +2584,13 @@ export const zh: Record<TranslationKey, string> = {
|
||||
'contextIndicator.updatedNow': '刚刚更新',
|
||||
'contextIndicator.updatedMinutes': '{count} 分钟前更新',
|
||||
'contextIndicator.estimate': '估算',
|
||||
'contextIndicator.sessionUsage': '此次会话',
|
||||
'contextIndicator.sessionTotalTokens': '总 token',
|
||||
'contextIndicator.sessionCacheHit': '缓存命中',
|
||||
'contextIndicator.sessionSpeed': '生成速度',
|
||||
'contextIndicator.sessionApiDuration': 'API 耗时',
|
||||
'contextIndicator.sessionSpeedUnit': 'tok/s',
|
||||
'contextIndicator.sessionScopeNote': '不含子代理用量',
|
||||
'chat.navigate': '导航',
|
||||
'chat.select': '选择',
|
||||
'chat.dismiss': '关闭',
|
||||
|
||||
@@ -0,0 +1,137 @@
|
||||
import { describe, expect, it } from 'vitest'
|
||||
import {
|
||||
deriveSessionUsageMetrics,
|
||||
formatCacheHitRate,
|
||||
formatCompactTokens,
|
||||
formatTokensPerSecond,
|
||||
} from './sessionUsageMetrics'
|
||||
|
||||
function usage(overrides: Partial<Parameters<typeof deriveSessionUsageMetrics>[0]> = {}) {
|
||||
return {
|
||||
totalInputTokens: 0,
|
||||
totalOutputTokens: 0,
|
||||
totalCacheReadInputTokens: 0,
|
||||
totalCacheCreationInputTokens: 0,
|
||||
...overrides,
|
||||
}
|
||||
}
|
||||
|
||||
describe('deriveSessionUsageMetrics', () => {
|
||||
it('counts each of the four buckets exactly once', () => {
|
||||
const metrics = deriveSessionUsageMetrics(usage({
|
||||
totalInputTokens: 1_000,
|
||||
totalOutputTokens: 200,
|
||||
totalCacheReadInputTokens: 8_000,
|
||||
totalCacheCreationInputTokens: 500,
|
||||
}))
|
||||
|
||||
// The buckets are disjoint, so the total is a plain sum — if a provider ever reported
|
||||
// cache reads inside input_tokens this would double-count them.
|
||||
expect(metrics.totalTokens).toBe(9_700)
|
||||
expect(metrics.promptTokens).toBe(9_500)
|
||||
})
|
||||
|
||||
it('measures cache hits against the prompt side, never against output', () => {
|
||||
const metrics = deriveSessionUsageMetrics(usage({
|
||||
totalInputTokens: 1_000,
|
||||
totalOutputTokens: 9_000,
|
||||
totalCacheReadInputTokens: 9_000,
|
||||
}))
|
||||
|
||||
// 9000 / (1000 + 9000) — a denominator that included output would report 82% here and
|
||||
// let a chatty reply make the cache look worse than it is.
|
||||
expect(metrics.cacheHitRate).toBeCloseTo(0.9, 10)
|
||||
})
|
||||
|
||||
it('withholds a cache hit rate until prompt tokens exist', () => {
|
||||
expect(deriveSessionUsageMetrics(usage({ totalOutputTokens: 500 })).cacheHitRate).toBeNull()
|
||||
})
|
||||
|
||||
it('derives tokens per second from the decode span only', () => {
|
||||
const metrics = deriveSessionUsageMetrics(usage({
|
||||
totalOutputTokens: 1_000,
|
||||
totalDecodeDuration: 5_000,
|
||||
}))
|
||||
|
||||
expect(metrics.tokensPerSecond).toBe(200)
|
||||
})
|
||||
|
||||
it('withholds tokens per second when no decode span was reported', () => {
|
||||
// Transcript-sourced usage has no generation timing. Falling back to wall clock would
|
||||
// divide by a span that includes tool execution and invent a rate.
|
||||
const metrics = deriveSessionUsageMetrics(usage({
|
||||
totalOutputTokens: 1_000,
|
||||
totalDecodeDuration: 0,
|
||||
}))
|
||||
|
||||
expect(metrics.tokensPerSecond).toBeNull()
|
||||
})
|
||||
|
||||
it('treats missing and non-finite fields as zero rather than NaN', () => {
|
||||
const metrics = deriveSessionUsageMetrics({
|
||||
totalInputTokens: Number.NaN,
|
||||
totalOutputTokens: 100,
|
||||
totalCacheReadInputTokens: undefined as unknown as number,
|
||||
totalCacheCreationInputTokens: -5,
|
||||
totalDecodeDuration: undefined,
|
||||
})
|
||||
|
||||
expect(metrics.totalTokens).toBe(100)
|
||||
expect(metrics.cacheHitRate).toBeNull()
|
||||
expect(metrics.tokensPerSecond).toBeNull()
|
||||
})
|
||||
})
|
||||
|
||||
describe('formatCacheHitRate', () => {
|
||||
it.each([
|
||||
[0, '0%'],
|
||||
[0.5, '50.0%'],
|
||||
[0.982, '98.2%'],
|
||||
[1, '100%'],
|
||||
])('renders %s as %s', (rate, expected) => {
|
||||
expect(formatCacheHitRate(rate)).toBe(expected)
|
||||
})
|
||||
|
||||
it('never rounds a partial hit up to a flat 100%', () => {
|
||||
// 0.9996 * 100 = 99.96 -> toFixed(1) would print "100.0%", which claims a perfect cache.
|
||||
expect(formatCacheHitRate(0.9996)).toBe('99.96%')
|
||||
})
|
||||
|
||||
it('floors rates that round to 100.00 at two decimals', () => {
|
||||
expect(formatCacheHitRate(0.999_999)).toBe('99.99%')
|
||||
})
|
||||
|
||||
it('clamps nonsense to a displayable value', () => {
|
||||
expect(formatCacheHitRate(Number.NaN)).toBe('0%')
|
||||
expect(formatCacheHitRate(-1)).toBe('0%')
|
||||
})
|
||||
})
|
||||
|
||||
describe('formatTokensPerSecond', () => {
|
||||
it('keeps a decimal only where it carries information', () => {
|
||||
expect(formatTokensPerSecond(9.44)).toBe('9.4')
|
||||
expect(formatTokensPerSecond(42.6)).toBe('43')
|
||||
expect(formatTokensPerSecond(1_234.9)).toBe('1235')
|
||||
})
|
||||
|
||||
it('renders an unavailable rate as a placeholder, not zero', () => {
|
||||
expect(formatTokensPerSecond(0)).toBe('--')
|
||||
expect(formatTokensPerSecond(Number.NaN)).toBe('--')
|
||||
})
|
||||
})
|
||||
|
||||
describe('formatCompactTokens', () => {
|
||||
it.each([
|
||||
[812, '812'],
|
||||
[9_500, '9.5K'],
|
||||
[375_372, '375K'],
|
||||
[8_100_000, '8.1M'],
|
||||
])('renders %s as %s', (value, expected) => {
|
||||
expect(formatCompactTokens(value)).toBe(expected)
|
||||
})
|
||||
|
||||
it('promotes a value that would round into a four-digit smaller unit', () => {
|
||||
// 999_949/1000 rounds to "1000" at zero decimals; showing "1000K" reads as a bug.
|
||||
expect(formatCompactTokens(999_949)).toBe('1.0M')
|
||||
})
|
||||
})
|
||||
@@ -0,0 +1,97 @@
|
||||
/**
|
||||
* Session-level token accounting for the context panel.
|
||||
*
|
||||
* The four buckets the CLI reports are disjoint: `input_tokens` never includes cached tokens, so
|
||||
* summing them counts each token exactly once. (Providers whose wire format folds cache hits into
|
||||
* the prompt total are adapted on the way in — see `src/server/proxy/transform/usage.ts`.) That
|
||||
* invariant is the reason this file can add first and ask questions later; a source that ever
|
||||
* reports inclusive input would silently inflate both the total and the cache hit rate.
|
||||
*/
|
||||
|
||||
export type SessionUsageLike = {
|
||||
totalInputTokens: number
|
||||
totalOutputTokens: number
|
||||
totalCacheReadInputTokens: number
|
||||
totalCacheCreationInputTokens: number
|
||||
totalDecodeDuration?: number
|
||||
}
|
||||
|
||||
export type SessionUsageMetrics = {
|
||||
/** Every token the session moved, counting a cached token once. */
|
||||
totalTokens: number
|
||||
/** Prompt-side tokens only: the denominator a cache hit rate is meaningful against. */
|
||||
promptTokens: number
|
||||
cachedTokens: number
|
||||
/** `null` when the session has sent no prompt tokens yet. */
|
||||
cacheHitRate: number | null
|
||||
/** `null` when no decode span was reported — see below. */
|
||||
tokensPerSecond: number | null
|
||||
}
|
||||
|
||||
function finite(value: number | undefined): number {
|
||||
return typeof value === 'number' && Number.isFinite(value) && value > 0 ? value : 0
|
||||
}
|
||||
|
||||
/**
|
||||
* Derives the panel's headline numbers.
|
||||
*
|
||||
* `tokensPerSecond` divides output tokens by the time the model actually spent emitting them, so
|
||||
* tool execution and prefill wait are excluded. A caller that only has a transcript (no decode
|
||||
* spans) gets `null` rather than a rate computed against wall clock: dividing by a span that
|
||||
* includes 40 seconds of `Bash` would report a speed the model never ran at.
|
||||
*/
|
||||
export function deriveSessionUsageMetrics(usage: SessionUsageLike): SessionUsageMetrics {
|
||||
const input = finite(usage.totalInputTokens)
|
||||
const output = finite(usage.totalOutputTokens)
|
||||
const cacheRead = finite(usage.totalCacheReadInputTokens)
|
||||
const cacheWrite = finite(usage.totalCacheCreationInputTokens)
|
||||
const decodeMs = finite(usage.totalDecodeDuration)
|
||||
|
||||
const promptTokens = input + cacheRead + cacheWrite
|
||||
return {
|
||||
totalTokens: promptTokens + output,
|
||||
promptTokens,
|
||||
cachedTokens: cacheRead,
|
||||
cacheHitRate: promptTokens > 0 ? cacheRead / promptTokens : null,
|
||||
tokensPerSecond: decodeMs > 0 && output > 0 ? output / (decodeMs / 1000) : null,
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Formats a cache hit rate without ever rounding a partial hit up to a flat 100%.
|
||||
*
|
||||
* A session at 99.96% is *not* fully cached, and printing "100%" would tell the user something
|
||||
* false about both their bill and their prompt stability. Widening the precision is the honest
|
||||
* fix; only a rate that is exactly 1 renders as 100%.
|
||||
*/
|
||||
export function formatCacheHitRate(rate: number): string {
|
||||
if (!Number.isFinite(rate) || rate <= 0) return '0%'
|
||||
if (rate >= 1) return '100%'
|
||||
const percent = rate * 100
|
||||
const oneDecimal = percent.toFixed(1)
|
||||
if (oneDecimal !== '100.0') return `${oneDecimal}%`
|
||||
const twoDecimals = percent.toFixed(2)
|
||||
// 99.995% and up still rounds to 100.00; floor it so the maximum shown below
|
||||
// a true hit is visibly below a true hit.
|
||||
return twoDecimals === '100.00' ? '99.99%' : `${twoDecimals}%`
|
||||
}
|
||||
|
||||
/** `100`, `42`, `9.4` — one decimal only while the number is small enough to need it. */
|
||||
export function formatTokensPerSecond(value: number): string {
|
||||
if (!Number.isFinite(value) || value <= 0) return '--'
|
||||
return value >= 10 ? `${Math.round(value)}` : `${value.toFixed(1)}`
|
||||
}
|
||||
|
||||
/** `1.2M`, `375K`, `812` — compact enough for a stat row, never a lie about magnitude. */
|
||||
export function formatCompactTokens(value: number): string {
|
||||
if (!Number.isFinite(value) || value <= 0) return '0'
|
||||
if (value < 1_000) return `${Math.round(value)}`
|
||||
const thousands = value / 1_000
|
||||
const decimals = thousands >= 100 ? 0 : 1
|
||||
// Rounding can push a value just under the next unit up to a full thousand of the smaller one
|
||||
// (999_949 reads as "1000K"); promote it so the row never shows four digits of a smaller unit.
|
||||
if (Number(thousands.toFixed(decimals)) >= 1_000) {
|
||||
return `${(value / 1_000_000).toFixed(1)}M`
|
||||
}
|
||||
return `${thousands.toFixed(decimals)}K`
|
||||
}
|
||||
@@ -2871,6 +2871,46 @@ describe('chatStore history mapping', () => {
|
||||
]))
|
||||
})
|
||||
|
||||
it('counts a multi-block reply once when restoring token usage from history', async () => {
|
||||
// Three lines sharing a `usageKey` are one reply's content blocks. Summing per line would
|
||||
// report 3x; this is the same inflation the server-side transcript readers dedupe away.
|
||||
const blockLine = (usageKey: string) => ({
|
||||
id: `line-${usageKey}`,
|
||||
type: 'assistant' as const,
|
||||
timestamp: '2026-08-31T00:00:00.000Z',
|
||||
content: [{ type: 'text', text: 'block' }],
|
||||
usage: { input_tokens: 100, output_tokens: 250, cache_read_input_tokens: 1_000 },
|
||||
usageKey,
|
||||
})
|
||||
const distinctReply = {
|
||||
id: 'line-second-reply',
|
||||
type: 'assistant' as const,
|
||||
timestamp: '2026-08-31T00:01:00.000Z',
|
||||
content: [{ type: 'text', text: 'second' }],
|
||||
usage: { input_tokens: 10, output_tokens: 70 },
|
||||
usageKey: 'msg_second\0req_second',
|
||||
}
|
||||
vi.mocked(sessionsApi.getMessages).mockResolvedValueOnce({
|
||||
messages: [
|
||||
blockLine('msg_first\0req_first'),
|
||||
blockLine('msg_first\0req_first'),
|
||||
blockLine('msg_first\0req_first'),
|
||||
distinctReply,
|
||||
] as never,
|
||||
})
|
||||
useChatStore.setState({
|
||||
sessions: { [TEST_SESSION_ID]: makeSession({ messages: [] }) },
|
||||
})
|
||||
|
||||
await useChatStore.getState().loadHistory(TEST_SESSION_ID)
|
||||
|
||||
expect(useChatStore.getState().sessions[TEST_SESSION_ID]?.tokenUsage).toEqual({
|
||||
input_tokens: 110,
|
||||
output_tokens: 320,
|
||||
cache_read_tokens: 1_000,
|
||||
})
|
||||
})
|
||||
|
||||
it('does not replace newer live token usage with a stale cold snapshot', async () => {
|
||||
let resolveHistory!: (value: { messages: MessageEntry[] }) => void
|
||||
vi.mocked(sessionsApi.getMessages).mockReturnValueOnce(new Promise((resolve) => {
|
||||
|
||||
@@ -2072,10 +2072,19 @@ function summarizeTokenUsageFromHistory(messages: MessageEntry[]): TokenUsage |
|
||||
let outputTokens = 0
|
||||
let cacheReadTokens = 0
|
||||
let cacheCreationTokens = 0
|
||||
// A reply with thinking + text + a dozen tool_use blocks arrives as fourteen lines that each
|
||||
// repeat the whole `usage` object. Summing per line is the 2.2x inflation the transcript
|
||||
// readers carry; the server stamps `usageKey` so this only has to dedupe on it. Lines with
|
||||
// no key are always counted, matching the transcript readers.
|
||||
const countedUsageKeys = new Set<string>()
|
||||
|
||||
for (const message of messages) {
|
||||
const usage = message.usage
|
||||
if (!usage) continue
|
||||
if (message.usageKey) {
|
||||
if (countedUsageKeys.has(message.usageKey)) continue
|
||||
countedUsageKeys.add(message.usageKey)
|
||||
}
|
||||
inputTokens += readUsageToken(usage.input_tokens)
|
||||
outputTokens += readUsageToken(usage.output_tokens)
|
||||
cacheReadTokens += readUsageToken(usage.cache_read_input_tokens)
|
||||
|
||||
@@ -126,7 +126,7 @@ export type ServerMessage =
|
||||
turnActive: boolean
|
||||
}
|
||||
| { type: 'user_message_replay'; content: string }
|
||||
| { type: 'message_complete'; usage: TokenUsage }
|
||||
| { type: 'message_complete'; usage: TokenUsage; timing?: TurnTiming }
|
||||
/** `complete` marks a whole thinking block; without it `text` is a stream fragment. */
|
||||
| { type: 'thinking'; text: string; complete?: boolean }
|
||||
| { type: 'status'; state: ChatState; verb?: string; attemptStart?: boolean }
|
||||
@@ -179,6 +179,14 @@ export type TokenUsage = {
|
||||
cache_creation_tokens?: number
|
||||
}
|
||||
|
||||
/** Mirrors the server's `TurnTiming`: milliseconds, `decode_ms` excludes prefill and tools. */
|
||||
export type TurnTiming = {
|
||||
duration_ms: number
|
||||
duration_api_ms: number
|
||||
ttft_ms: number
|
||||
decode_ms: number
|
||||
}
|
||||
|
||||
export type ChatState = 'idle' | 'thinking' | 'compacting' | 'tool_executing' | 'streaming' | 'permission_pending'
|
||||
|
||||
export type ApiRetryState = {
|
||||
|
||||
@@ -51,6 +51,12 @@ export type MessageEntry = {
|
||||
timestamp: string
|
||||
model?: string
|
||||
usage?: MessageUsage
|
||||
/**
|
||||
* Identity of the API response this `usage` belongs to, when it has one. One assistant reply
|
||||
* is persisted as several lines that each repeat the whole `usage` object, so anything that
|
||||
* totals usage must count each key once. Absent means the line carries no id — count it.
|
||||
*/
|
||||
usageKey?: string
|
||||
parentUuid?: string
|
||||
parentToolUseId?: string
|
||||
isSidechain?: boolean
|
||||
|
||||
@@ -3,6 +3,7 @@ import type { ContentBlockParam } from '@anthropic-ai/sdk/resources/messages.mjs
|
||||
import { randomUUID } from 'crypto'
|
||||
import last from 'lodash-es/last.js'
|
||||
import {
|
||||
addToTotalGenerationDuration,
|
||||
getSessionId,
|
||||
isSessionPersistenceDisabled,
|
||||
} from 'src/bootstrap/state.js'
|
||||
@@ -192,6 +193,11 @@ export class QueryEngine {
|
||||
private abortController: AbortController
|
||||
private permissionDenials: SDKPermissionDenial[]
|
||||
private totalUsage: NonNullableUsage
|
||||
// Generation timing for this turn, summed over every API request it made. `decodeMs`
|
||||
// excludes prefill and tool execution, so it is the denominator a tokens/sec reading
|
||||
// needs; `ttftMs` is kept for the request-to-first-token wait it deliberately omits.
|
||||
private totalDecodeMs = 0
|
||||
private totalTtftMs = 0
|
||||
private hasHandledOrphanedPermission = false
|
||||
private readFileState: FileStateCache
|
||||
// Turn-scoped skill discovery tracking (feeds was_discovered on
|
||||
@@ -645,6 +651,11 @@ export class QueryEngine {
|
||||
is_error: false,
|
||||
duration_ms: Date.now() - startTime,
|
||||
duration_api_ms: getTotalAPIDuration(),
|
||||
// Generation-only timings for this turn. `duration_api_ms` covers the whole request
|
||||
// including prefill, so a tokens/sec reading built from it understates fast models on
|
||||
// long contexts; decode_ms is the span tokens were actually being emitted over.
|
||||
ttft_ms: this.totalTtftMs,
|
||||
decode_ms: this.totalDecodeMs,
|
||||
num_turns: messages.length - 1,
|
||||
result: resultText ?? '',
|
||||
stop_reason: null,
|
||||
@@ -682,6 +693,9 @@ export class QueryEngine {
|
||||
|
||||
// Track current message usage (reset on each message_start)
|
||||
let currentMessageUsage: NonNullableUsage = EMPTY_USAGE
|
||||
// Same scope as currentMessageUsage: an attempt that dies before message_stop must
|
||||
// discard its timings too, otherwise a retried request bills prefill time twice.
|
||||
let currentMessageTtftMs = 0
|
||||
let turnCount = 1
|
||||
let hasAcknowledgedInitialMessages = false
|
||||
// Track structured output from StructuredOutput tool calls
|
||||
@@ -819,6 +833,7 @@ export class QueryEngine {
|
||||
currentMessageUsage,
|
||||
message.event.message.usage,
|
||||
)
|
||||
currentMessageTtftMs = message.ttftMs ?? 0
|
||||
}
|
||||
if (message.event.type === 'message_delta') {
|
||||
currentMessageUsage = updateUsage(
|
||||
@@ -839,6 +854,14 @@ export class QueryEngine {
|
||||
this.totalUsage,
|
||||
currentMessageUsage,
|
||||
)
|
||||
this.totalDecodeMs += message.decodeMs ?? 0
|
||||
this.totalTtftMs += currentMessageTtftMs
|
||||
// Session-scoped twin of the turn totals above: survives across turns so the
|
||||
// usage snapshot can report generation speed for the whole conversation.
|
||||
addToTotalGenerationDuration(
|
||||
message.decodeMs ?? 0,
|
||||
currentMessageTtftMs,
|
||||
)
|
||||
}
|
||||
|
||||
if (includePartialMessages) {
|
||||
|
||||
@@ -52,6 +52,10 @@ type State = {
|
||||
totalAPIDuration: number
|
||||
totalAPIDurationWithoutRetries: number
|
||||
totalToolDuration: number
|
||||
// Generation-only timing: the span from the first emitted delta to the end of each API
|
||||
// response, and the prefill wait that precedes it. See QueryEngine's per-turn accumulators.
|
||||
totalDecodeDuration: number
|
||||
totalTtftDuration: number
|
||||
turnHookDurationMs: number
|
||||
turnToolDurationMs: number
|
||||
turnClassifierDurationMs: number
|
||||
@@ -285,6 +289,8 @@ function getInitialState(): State {
|
||||
totalAPIDuration: 0,
|
||||
totalAPIDurationWithoutRetries: 0,
|
||||
totalToolDuration: 0,
|
||||
totalDecodeDuration: 0,
|
||||
totalTtftDuration: 0,
|
||||
turnHookDurationMs: 0,
|
||||
turnToolDurationMs: 0,
|
||||
turnClassifierDurationMs: 0,
|
||||
@@ -548,10 +554,28 @@ export function addToTotalDurationState(
|
||||
STATE.totalAPIDurationWithoutRetries += durationWithoutRetries
|
||||
}
|
||||
|
||||
export function addToTotalGenerationDuration(
|
||||
decodeDuration: number,
|
||||
ttftDuration: number,
|
||||
): void {
|
||||
STATE.totalDecodeDuration += decodeDuration
|
||||
STATE.totalTtftDuration += ttftDuration
|
||||
}
|
||||
|
||||
export function getTotalDecodeDuration(): number {
|
||||
return STATE.totalDecodeDuration
|
||||
}
|
||||
|
||||
export function getTotalTtftDuration(): number {
|
||||
return STATE.totalTtftDuration
|
||||
}
|
||||
|
||||
export function resetTotalDurationStateAndCost_FOR_TESTS_ONLY(): void {
|
||||
STATE.totalAPIDuration = 0
|
||||
STATE.totalAPIDurationWithoutRetries = 0
|
||||
STATE.totalCostUSD = 0
|
||||
STATE.totalDecodeDuration = 0
|
||||
STATE.totalTtftDuration = 0
|
||||
}
|
||||
|
||||
export function addToTotalCostState(
|
||||
@@ -866,6 +890,8 @@ export function resetCostState(): void {
|
||||
STATE.totalAPIDuration = 0
|
||||
STATE.totalAPIDurationWithoutRetries = 0
|
||||
STATE.totalToolDuration = 0
|
||||
STATE.totalDecodeDuration = 0
|
||||
STATE.totalTtftDuration = 0
|
||||
STATE.startTime = Date.now()
|
||||
STATE.totalLinesAdded = 0
|
||||
STATE.totalLinesRemoved = 0
|
||||
@@ -882,6 +908,8 @@ export function setCostStateForRestore({
|
||||
totalCostUSD,
|
||||
totalAPIDuration,
|
||||
totalAPIDurationWithoutRetries,
|
||||
totalDecodeDuration,
|
||||
totalTtftDuration,
|
||||
totalToolDuration,
|
||||
totalLinesAdded,
|
||||
totalLinesRemoved,
|
||||
@@ -891,6 +919,8 @@ export function setCostStateForRestore({
|
||||
totalCostUSD: number
|
||||
totalAPIDuration: number
|
||||
totalAPIDurationWithoutRetries: number
|
||||
totalDecodeDuration: number
|
||||
totalTtftDuration: number
|
||||
totalToolDuration: number
|
||||
totalLinesAdded: number
|
||||
totalLinesRemoved: number
|
||||
@@ -900,6 +930,8 @@ export function setCostStateForRestore({
|
||||
STATE.totalCostUSD = totalCostUSD
|
||||
STATE.totalAPIDuration = totalAPIDuration
|
||||
STATE.totalAPIDurationWithoutRetries = totalAPIDurationWithoutRetries
|
||||
STATE.totalDecodeDuration = totalDecodeDuration
|
||||
STATE.totalTtftDuration = totalTtftDuration
|
||||
STATE.totalToolDuration = totalToolDuration
|
||||
STATE.totalLinesAdded = totalLinesAdded
|
||||
STATE.totalLinesRemoved = totalLinesRemoved
|
||||
|
||||
@@ -13,11 +13,13 @@ import {
|
||||
getTotalCacheCreationInputTokens,
|
||||
getTotalCacheReadInputTokens,
|
||||
getTotalCostUSD,
|
||||
getTotalDecodeDuration,
|
||||
getTotalDuration,
|
||||
getTotalInputTokens,
|
||||
getTotalLinesAdded,
|
||||
getTotalLinesRemoved,
|
||||
getTotalOutputTokens,
|
||||
getTotalTtftDuration,
|
||||
getTotalToolDuration,
|
||||
getTotalWebSearchRequests,
|
||||
getUsageForModel,
|
||||
@@ -73,6 +75,10 @@ export type SessionUsageSnapshot = {
|
||||
costDisplay: string
|
||||
hasUnknownModelCost: boolean
|
||||
totalAPIDuration: number
|
||||
// Time the model spent emitting tokens, excluding prefill and tool execution. Zero when
|
||||
// no streamed response reported a decode span (non-streaming fallback, aborted turn).
|
||||
totalDecodeDuration: number
|
||||
totalTtftDuration: number
|
||||
totalDuration: number
|
||||
totalLinesAdded: number
|
||||
totalLinesRemoved: number
|
||||
@@ -100,6 +106,8 @@ type StoredCostState = {
|
||||
totalCostUSD: number
|
||||
totalAPIDuration: number
|
||||
totalAPIDurationWithoutRetries: number
|
||||
totalDecodeDuration: number
|
||||
totalTtftDuration: number
|
||||
totalToolDuration: number
|
||||
totalLinesAdded: number
|
||||
totalLinesRemoved: number
|
||||
@@ -142,6 +150,8 @@ export function getStoredSessionCosts(
|
||||
totalAPIDuration: projectConfig.lastAPIDuration ?? 0,
|
||||
totalAPIDurationWithoutRetries:
|
||||
projectConfig.lastAPIDurationWithoutRetries ?? 0,
|
||||
totalDecodeDuration: projectConfig.lastDecodeDuration ?? 0,
|
||||
totalTtftDuration: projectConfig.lastTtftDuration ?? 0,
|
||||
totalToolDuration: projectConfig.lastToolDuration ?? 0,
|
||||
totalLinesAdded: projectConfig.lastLinesAdded ?? 0,
|
||||
totalLinesRemoved: projectConfig.lastLinesRemoved ?? 0,
|
||||
@@ -174,6 +184,8 @@ export function saveCurrentSessionCosts(fpsMetrics?: FpsMetrics): void {
|
||||
lastCost: getTotalCostUSD(),
|
||||
lastAPIDuration: getTotalAPIDuration(),
|
||||
lastAPIDurationWithoutRetries: getTotalAPIDurationWithoutRetries(),
|
||||
lastDecodeDuration: getTotalDecodeDuration(),
|
||||
lastTtftDuration: getTotalTtftDuration(),
|
||||
lastToolDuration: getTotalToolDuration(),
|
||||
lastDuration: getTotalDuration(),
|
||||
lastLinesAdded: getTotalLinesAdded(),
|
||||
@@ -277,6 +289,8 @@ export function getSessionUsageSnapshot(): SessionUsageSnapshot {
|
||||
costDisplay: formatCost(getTotalCostUSD()),
|
||||
hasUnknownModelCost: hasUnknownModelCost(),
|
||||
totalAPIDuration: getTotalAPIDuration(),
|
||||
totalDecodeDuration: getTotalDecodeDuration(),
|
||||
totalTtftDuration: getTotalTtftDuration(),
|
||||
totalDuration: getTotalDuration(),
|
||||
totalLinesAdded: getTotalLinesAdded(),
|
||||
totalLinesRemoved: getTotalLinesRemoved(),
|
||||
|
||||
@@ -0,0 +1,157 @@
|
||||
import { afterEach, beforeEach, describe, expect, it } from 'bun:test'
|
||||
import * as fs from 'node:fs/promises'
|
||||
import * as os from 'node:os'
|
||||
import * as path from 'node:path'
|
||||
import { handleSessionsApi } from '../api/sessions.js'
|
||||
import { conversationService } from '../services/conversationService.js'
|
||||
import { __resetWebSocketHandlerStateForTests } from '../ws/handler.js'
|
||||
|
||||
/**
|
||||
* `usageOnly` exists so the context panel can poll a live session's totals without paying for
|
||||
* the full inspection — which additionally scans every skill directory on disk, asks the CLI
|
||||
* for MCP status, and re-reads the whole transcript to cross-check usage. Those three are fine
|
||||
* once; they are not fine every few seconds. These tests pin both the payload and, more
|
||||
* importantly, the set of CLI controls the cheap path is allowed to issue.
|
||||
*/
|
||||
|
||||
const SESSION_ID = 'session-usage-only'
|
||||
|
||||
let tempRoot: string
|
||||
let workDir: string
|
||||
let requestedSubtypes: string[]
|
||||
let original: {
|
||||
hasSession: typeof conversationService.hasSession
|
||||
getSessionWorkDir: typeof conversationService.getSessionWorkDir
|
||||
getSessionPermissionMode: typeof conversationService.getSessionPermissionMode
|
||||
getSessionInitMessage: typeof conversationService.getSessionInitMessage
|
||||
getRecentSdkMessages: typeof conversationService.getRecentSdkMessages
|
||||
requestControl: typeof conversationService.requestControl
|
||||
}
|
||||
|
||||
const usageSnapshot = {
|
||||
totalCostUSD: 0.5,
|
||||
costDisplay: '$0.50',
|
||||
hasUnknownModelCost: false,
|
||||
totalAPIDuration: 42_000,
|
||||
totalDecodeDuration: 12_000,
|
||||
totalTtftDuration: 3_000,
|
||||
totalDuration: 600,
|
||||
totalLinesAdded: 0,
|
||||
totalLinesRemoved: 0,
|
||||
totalInputTokens: 1_000,
|
||||
totalOutputTokens: 2_400,
|
||||
totalCacheReadInputTokens: 9_000,
|
||||
totalCacheCreationInputTokens: 0,
|
||||
totalWebSearchRequests: 0,
|
||||
models: [],
|
||||
}
|
||||
|
||||
async function inspect(query: string): Promise<Record<string, unknown>> {
|
||||
const url = new URL(`http://localhost/api/sessions/${SESSION_ID}/inspection${query}`)
|
||||
const response = await handleSessionsApi(
|
||||
new Request(url, { method: 'GET' }),
|
||||
url,
|
||||
['api', 'sessions', SESSION_ID, 'inspection'],
|
||||
)
|
||||
expect(response.status).toBe(200)
|
||||
return await response.json() as Record<string, unknown>
|
||||
}
|
||||
|
||||
beforeEach(async () => {
|
||||
tempRoot = await fs.mkdtemp(path.join(os.tmpdir(), 'cc-haha-usage-only-'))
|
||||
workDir = path.join(tempRoot, 'project')
|
||||
await fs.mkdir(workDir, { recursive: true })
|
||||
__resetWebSocketHandlerStateForTests()
|
||||
|
||||
requestedSubtypes = []
|
||||
original = {
|
||||
hasSession: conversationService.hasSession,
|
||||
getSessionWorkDir: conversationService.getSessionWorkDir,
|
||||
getSessionPermissionMode: conversationService.getSessionPermissionMode,
|
||||
getSessionInitMessage: conversationService.getSessionInitMessage,
|
||||
getRecentSdkMessages: conversationService.getRecentSdkMessages,
|
||||
requestControl: conversationService.requestControl,
|
||||
}
|
||||
|
||||
conversationService.hasSession = ((id: string) =>
|
||||
id === SESSION_ID) as typeof conversationService.hasSession
|
||||
conversationService.getSessionWorkDir = (() =>
|
||||
workDir) as typeof conversationService.getSessionWorkDir
|
||||
conversationService.getSessionPermissionMode = (() =>
|
||||
'default') as typeof conversationService.getSessionPermissionMode
|
||||
conversationService.getSessionInitMessage = (() => ({
|
||||
type: 'system',
|
||||
subtype: 'init',
|
||||
model: 'claude-opus-4-7',
|
||||
cwd: workDir,
|
||||
tools: [],
|
||||
mcp_servers: [],
|
||||
slash_commands: [],
|
||||
})) as typeof conversationService.getSessionInitMessage
|
||||
conversationService.getRecentSdkMessages = (() =>
|
||||
[]) as typeof conversationService.getRecentSdkMessages
|
||||
conversationService.requestControl = (async (
|
||||
_sessionId: string,
|
||||
request: { subtype: string },
|
||||
) => {
|
||||
requestedSubtypes.push(request.subtype)
|
||||
return request.subtype === 'get_session_usage' ? usageSnapshot : {}
|
||||
}) as typeof conversationService.requestControl
|
||||
})
|
||||
|
||||
afterEach(async () => {
|
||||
conversationService.hasSession = original.hasSession
|
||||
conversationService.getSessionWorkDir = original.getSessionWorkDir
|
||||
conversationService.getSessionPermissionMode = original.getSessionPermissionMode
|
||||
conversationService.getSessionInitMessage = original.getSessionInitMessage
|
||||
conversationService.getRecentSdkMessages = original.getRecentSdkMessages
|
||||
conversationService.requestControl = original.requestControl
|
||||
__resetWebSocketHandlerStateForTests()
|
||||
await fs.rm(tempRoot, { recursive: true, force: true })
|
||||
})
|
||||
|
||||
describe('session inspection: usageOnly', () => {
|
||||
it('returns running totals from a single get_session_usage control', async () => {
|
||||
const body = await inspect('?includeContext=0&usageOnly=1')
|
||||
|
||||
expect(requestedSubtypes).toEqual(['get_session_usage'])
|
||||
expect(body.usage).toEqual({ ...usageSnapshot, source: 'current_process' })
|
||||
})
|
||||
|
||||
it('skips MCP status, unlike the full inspection', async () => {
|
||||
await inspect('?includeContext=0&usageOnly=1')
|
||||
|
||||
expect(requestedSubtypes).not.toContain('mcp_status')
|
||||
expect(requestedSubtypes).not.toContain('get_context_usage')
|
||||
})
|
||||
|
||||
it('does not report context, so a poll cannot be mistaken for a context refresh', async () => {
|
||||
const body = await inspect('?includeContext=0&usageOnly=1')
|
||||
|
||||
expect('context' in body).toBe(false)
|
||||
expect('contextEstimate' in body).toBe(false)
|
||||
})
|
||||
|
||||
it('still asks for the expensive controls on a full inspection', async () => {
|
||||
// The negative control for the tests above: if the cheap path were achieved by gutting the
|
||||
// full one, every one of these assertions would pass while the inspector lost its data.
|
||||
await inspect('?includeContext=1')
|
||||
|
||||
expect(requestedSubtypes).toContain('get_session_usage')
|
||||
expect(requestedSubtypes).toContain('get_context_usage')
|
||||
expect(requestedSubtypes).toContain('mcp_status')
|
||||
})
|
||||
|
||||
it('reports a control failure as an error instead of falling back to a transcript re-read', async () => {
|
||||
conversationService.requestControl = (async () => {
|
||||
throw new Error('CLI control timed out')
|
||||
}) as typeof conversationService.requestControl
|
||||
|
||||
const body = await inspect('?includeContext=0&usageOnly=1')
|
||||
|
||||
// Falling back would mean re-reading the whole JSONL on every tick, which is the cost this
|
||||
// mode exists to avoid; the panel keeps its last good numbers and retries instead.
|
||||
expect(body.usage).toBeUndefined()
|
||||
expect((body.errors as Record<string, string>)?.usage).toContain('CLI control timed out')
|
||||
})
|
||||
})
|
||||
@@ -3587,6 +3587,99 @@ describe('Sessions API', () => {
|
||||
expect(inspection.status.permissionMode).toBe('bypassPermissions')
|
||||
})
|
||||
|
||||
it('counts a multi-block assistant reply once when rebuilding transcript usage', async () => {
|
||||
const workDir = await fs.mkdtemp(path.join(tmpDir, 'api-session-usage-dedup-'))
|
||||
const sessionId = '11111111-2222-3333-4444-555555555555'
|
||||
const projectDir = '-tmp-api-session-usage-dedup'
|
||||
const messageId = 'msg_shared_reply'
|
||||
const replyUsage = {
|
||||
input_tokens: 100,
|
||||
output_tokens: 250,
|
||||
cache_read_input_tokens: 1_000,
|
||||
cache_creation_input_tokens: 20,
|
||||
}
|
||||
// Claude Code writes one JSONL line per content block of a reply and repeats the complete
|
||||
// `usage` object on every one. Three lines here stand for one reply with thinking + text +
|
||||
// tool_use; summing them raw is the 2.2x inflation `usageAccounting.ts` documents.
|
||||
const blockLine = () => ({
|
||||
parentUuid: null,
|
||||
isSidechain: false,
|
||||
type: 'assistant',
|
||||
message: {
|
||||
model: 'claude-opus-4-7',
|
||||
id: messageId,
|
||||
type: 'message',
|
||||
role: 'assistant',
|
||||
content: [{ type: 'text', text: 'block' }],
|
||||
usage: replyUsage,
|
||||
},
|
||||
uuid: crypto.randomUUID(),
|
||||
timestamp: '2026-01-01T00:02:00.000Z',
|
||||
sessionId,
|
||||
cwd: workDir,
|
||||
})
|
||||
await writeSessionFile(projectDir, sessionId, [
|
||||
makeSessionMetaEntry(workDir),
|
||||
makeUserEntry('go', crypto.randomUUID()),
|
||||
blockLine(),
|
||||
blockLine(),
|
||||
blockLine(),
|
||||
])
|
||||
|
||||
const res = await fetch(`${baseUrl}/api/sessions/${sessionId}/inspection?includeContext=0`)
|
||||
expect(res.status).toBe(200)
|
||||
const body = await res.json() as {
|
||||
usage?: {
|
||||
totalInputTokens: number
|
||||
totalOutputTokens: number
|
||||
totalCacheReadInputTokens: number
|
||||
totalCacheCreationInputTokens: number
|
||||
}
|
||||
}
|
||||
|
||||
expect(body.usage?.totalInputTokens).toBe(100)
|
||||
expect(body.usage?.totalOutputTokens).toBe(250)
|
||||
expect(body.usage?.totalCacheReadInputTokens).toBe(1_000)
|
||||
expect(body.usage?.totalCacheCreationInputTokens).toBe(20)
|
||||
})
|
||||
|
||||
it('still totals separate assistant replies separately after dedup', async () => {
|
||||
// The negative control for the test above: a dedup key that collapsed too much would make
|
||||
// every reply after the first free, which is a far worse error than the inflation it fixes.
|
||||
const workDir = await fs.mkdtemp(path.join(tmpDir, 'api-session-usage-distinct-'))
|
||||
const sessionId = '22222222-3333-4444-5555-666666666666'
|
||||
const projectDir = '-tmp-api-session-usage-distinct'
|
||||
const reply = (messageId: string, outputTokens: number) => ({
|
||||
parentUuid: null,
|
||||
isSidechain: false,
|
||||
type: 'assistant',
|
||||
message: {
|
||||
model: 'claude-opus-4-7',
|
||||
id: messageId,
|
||||
type: 'message',
|
||||
role: 'assistant',
|
||||
content: [{ type: 'text', text: 'reply' }],
|
||||
usage: { input_tokens: 10, output_tokens: outputTokens },
|
||||
},
|
||||
uuid: crypto.randomUUID(),
|
||||
timestamp: '2026-01-01T00:02:00.000Z',
|
||||
sessionId,
|
||||
cwd: workDir,
|
||||
})
|
||||
await writeSessionFile(projectDir, sessionId, [
|
||||
makeSessionMetaEntry(workDir),
|
||||
makeUserEntry('go', crypto.randomUUID()),
|
||||
reply('msg_first', 300),
|
||||
reply('msg_second', 70),
|
||||
])
|
||||
|
||||
const res = await fetch(`${baseUrl}/api/sessions/${sessionId}/inspection?includeContext=0`)
|
||||
const body = await res.json() as { usage?: { totalInputTokens: number; totalOutputTokens: number } }
|
||||
|
||||
expect(body.usage?.totalOutputTokens).toBe(370)
|
||||
expect(body.usage?.totalInputTokens).toBe(20)
|
||||
})
|
||||
|
||||
it('GET /api/sessions/repository-context should return branch launch metadata', async () => {
|
||||
const workDir = await createCleanGitRepo(tmpDir)
|
||||
const res = await fetch(
|
||||
|
||||
@@ -0,0 +1,91 @@
|
||||
import { describe, expect, it } from 'bun:test'
|
||||
import { translateCliMessage } from '../ws/handler.js'
|
||||
|
||||
/**
|
||||
* The CLI's `result` message has always carried `duration_ms` / `duration_api_ms`, and now
|
||||
* `decode_ms` / `ttft_ms` alongside them. The translation used to drop all four, which is why
|
||||
* nothing downstream could report how fast a session was generating. These pin the forwarding,
|
||||
* including the "absent means unknown" rule that keeps a client from dividing by zero.
|
||||
*/
|
||||
function resultMessages(overrides: Record<string, unknown>) {
|
||||
return translateCliMessage(
|
||||
{
|
||||
type: 'result',
|
||||
subtype: 'success',
|
||||
is_error: false,
|
||||
duration_ms: 0,
|
||||
duration_api_ms: 0,
|
||||
usage: { input_tokens: 10, output_tokens: 20 },
|
||||
...overrides,
|
||||
},
|
||||
'session-timing',
|
||||
) as Array<{ type: string; usage?: unknown; timing?: Record<string, number> }>
|
||||
}
|
||||
|
||||
describe('translateCliMessage: result timing', () => {
|
||||
it('forwards generation timings onto message_complete', () => {
|
||||
const [message] = resultMessages({
|
||||
duration_ms: 12_000,
|
||||
duration_api_ms: 9_000,
|
||||
decode_ms: 7_500,
|
||||
ttft_ms: 1_200,
|
||||
})
|
||||
|
||||
expect(message?.type).toBe('message_complete')
|
||||
expect(message?.timing).toEqual({
|
||||
duration_ms: 12_000,
|
||||
duration_api_ms: 9_000,
|
||||
ttft_ms: 1_200,
|
||||
decode_ms: 7_500,
|
||||
})
|
||||
// The token buckets must keep flowing untouched — timing rides alongside, not instead.
|
||||
expect(message?.usage).toEqual({ input_tokens: 10, output_tokens: 20 })
|
||||
})
|
||||
|
||||
it('omits timing entirely when the CLI reported none', () => {
|
||||
const [message] = resultMessages({})
|
||||
|
||||
expect(message?.type).toBe('message_complete')
|
||||
// Absent rather than zero: a zero decode span would be read as "instant" and turn into an
|
||||
// infinite tokens/sec, whereas absent lets the client withhold the figure.
|
||||
expect(message?.timing).toBeUndefined()
|
||||
expect('timing' in (message ?? {})).toBe(false)
|
||||
})
|
||||
|
||||
it('keeps a partial timing report instead of discarding it', () => {
|
||||
// An older CLI reports wall clock only; the remaining fields default to 0 so the shape
|
||||
// stays stable for consumers that read a single field.
|
||||
const [message] = resultMessages({ duration_ms: 5_000 })
|
||||
|
||||
expect(message?.timing).toEqual({
|
||||
duration_ms: 5_000,
|
||||
duration_api_ms: 0,
|
||||
ttft_ms: 0,
|
||||
decode_ms: 0,
|
||||
})
|
||||
})
|
||||
|
||||
it('ignores non-numeric timing values rather than emitting NaN', () => {
|
||||
const [message] = resultMessages({
|
||||
duration_ms: 'soon',
|
||||
decode_ms: null,
|
||||
ttft_ms: Number.NaN,
|
||||
duration_api_ms: Number.POSITIVE_INFINITY,
|
||||
})
|
||||
|
||||
expect(message?.timing).toBeUndefined()
|
||||
})
|
||||
|
||||
it('carries timing on an errored result too', () => {
|
||||
const messages = resultMessages({
|
||||
is_error: true,
|
||||
result: 'boom',
|
||||
duration_ms: 3_000,
|
||||
decode_ms: 2_000,
|
||||
})
|
||||
|
||||
const complete = messages.find((message) => message.type === 'message_complete')
|
||||
// Tokens were generated and billed before the failure; the timing is as real as the usage.
|
||||
expect(complete?.timing?.decode_ms).toBe(2_000)
|
||||
})
|
||||
})
|
||||
@@ -68,6 +68,13 @@ import { PET_SESSION_LIMIT } from '../petAccessPolicy.js'
|
||||
|
||||
const DEFAULT_GIT_INFO_COMMAND_TIMEOUT_MS = 3_000
|
||||
|
||||
/**
|
||||
* Budget for the polling `get_session_usage` control. Shorter than the inspection's basic
|
||||
* control timeout because the caller retries on its own cadence: a slow answer is worth less
|
||||
* than a stale one that blocks the next poll.
|
||||
*/
|
||||
const USAGE_ONLY_CONTROL_TIMEOUT_MS = 2_500
|
||||
|
||||
const workspaceService = new WorkspaceService(
|
||||
async (sessionId) => (
|
||||
conversationService.getSessionWorkDir(sessionId) ||
|
||||
@@ -987,6 +994,10 @@ async function getSessionSlashCommands(sessionId: string): Promise<Response> {
|
||||
async function getSessionInspection(req: Request, sessionId: string, url: URL): Promise<Response> {
|
||||
const includeContext = url.searchParams.get('includeContext') !== '0'
|
||||
const contextOnly = includeContext && url.searchParams.get('contextOnly') === '1'
|
||||
// Lightweight polling mode for the context panel: one `get_session_usage` control and
|
||||
// nothing else. The full inspection also scans the skills directory and re-reads the whole
|
||||
// transcript to cross-check usage, which is far too much work to repeat every few seconds.
|
||||
const usageOnly = !includeContext && url.searchParams.get('usageOnly') === '1'
|
||||
let transcriptSnapshot: Awaited<ReturnType<typeof sessionService.getInspectionTranscriptSnapshot>> | undefined
|
||||
const getTranscriptSnapshot = async () => {
|
||||
if (transcriptSnapshot !== undefined) return transcriptSnapshot
|
||||
@@ -1011,17 +1022,21 @@ async function getSessionInspection(req: Request, sessionId: string, url: URL):
|
||||
[...conversationService.getRecentSdkMessages(sessionId)]
|
||||
.reverse()
|
||||
.find((message) => message?.type === 'system' && message.subtype === 'init')
|
||||
const transcriptMetadata = !active || !initMessage
|
||||
const transcriptMetadata = !usageOnly && (!active || !initMessage)
|
||||
? (await getTranscriptSnapshot())?.metadata ?? null
|
||||
: null
|
||||
const cachedSlashCommands = getSlashCommands(sessionId)
|
||||
const hasCliSlashCommands = cachedSlashCommands.length > 0
|
||||
const skillSlashCommands = await listSkillSlashCommands(workDir, {
|
||||
includeCompiledIn: !hasCliSlashCommands,
|
||||
})
|
||||
const fallbackSlashCommands = hasCliSlashCommands
|
||||
? mergeSessionSlashCommands(cachedSlashCommands, skillSlashCommands)
|
||||
: skillSlashCommands
|
||||
// `listSkillSlashCommands` walks every skill directory on disk with no cache. The usage
|
||||
// poll does not need a command count, so it must not pay for one.
|
||||
const fallbackSlashCommands = usageOnly
|
||||
? []
|
||||
: hasCliSlashCommands
|
||||
? mergeSessionSlashCommands(
|
||||
cachedSlashCommands,
|
||||
await listSkillSlashCommands(workDir, { includeCompiledIn: false }),
|
||||
)
|
||||
: await listSkillSlashCommands(workDir, { includeCompiledIn: true })
|
||||
const slashCommandCount = Array.isArray(initMessage?.slash_commands)
|
||||
? initMessage.slash_commands.length
|
||||
: fallbackSlashCommands.length
|
||||
@@ -1063,6 +1078,28 @@ async function getSessionInspection(req: Request, sessionId: string, url: URL):
|
||||
}
|
||||
|
||||
const errors: Record<string, string> = {}
|
||||
if (usageOnly) {
|
||||
// No `mcp_status`, no skills scan, and deliberately no transcript cross-check: the
|
||||
// transcript re-read is what made this endpoint too expensive to poll. The CLI's own
|
||||
// running totals are the authoritative numbers for a live session anyway.
|
||||
try {
|
||||
response.usage = {
|
||||
...(await conversationService.requestControl(
|
||||
sessionId,
|
||||
{ subtype: 'get_session_usage' },
|
||||
USAGE_ONLY_CONTROL_TIMEOUT_MS,
|
||||
req.signal,
|
||||
)),
|
||||
source: 'current_process',
|
||||
}
|
||||
} catch (error) {
|
||||
throwIfRequestAborted(req)
|
||||
errors.usage = error instanceof Error ? error.message : String(error)
|
||||
}
|
||||
response.errors = errors
|
||||
return Response.json(response)
|
||||
}
|
||||
|
||||
if (contextOnly) {
|
||||
try {
|
||||
response.context = await conversationService.requestControl(
|
||||
|
||||
@@ -69,7 +69,11 @@ import type {
|
||||
} from './localIndex/sessionIndex.js'
|
||||
import type { LocalIndexStatus } from './localIndex/types.js'
|
||||
import { diagnosticsService } from './diagnosticsService.js'
|
||||
import { isForkInheritedUsageRecord } from '../../utils/usageAccounting.js'
|
||||
import {
|
||||
isBillableUsageRecord,
|
||||
isForkInheritedUsageRecord,
|
||||
usageRecordKey,
|
||||
} from '../../utils/usageAccounting.js'
|
||||
import {
|
||||
ProjectSessionHistory,
|
||||
type ProjectHistoryOptions,
|
||||
@@ -214,6 +218,15 @@ export type MessageEntry = {
|
||||
timestamp: string
|
||||
model?: string
|
||||
usage?: MessageUsage
|
||||
/**
|
||||
* Identity of the API response `usage` belongs to, when it has one.
|
||||
*
|
||||
* A single assistant reply is persisted as one line per content block, each repeating the
|
||||
* whole `usage` object, so any consumer that totals usage must count a given key once.
|
||||
* Computed here (rather than by each consumer) so the rule lives in one place; absent when
|
||||
* the line carries no message id, which by the same convention means "always count it".
|
||||
*/
|
||||
usageKey?: string
|
||||
parentUuid?: string
|
||||
parentToolUseId?: string
|
||||
isSidechain?: boolean
|
||||
@@ -257,6 +270,8 @@ export type TranscriptUsageSnapshot = {
|
||||
costDisplay: string
|
||||
hasUnknownModelCost: boolean
|
||||
totalAPIDuration: number
|
||||
totalDecodeDuration: number
|
||||
totalTtftDuration: number
|
||||
totalDuration: number
|
||||
totalLinesAdded: number
|
||||
totalLinesRemoved: number
|
||||
@@ -378,6 +393,35 @@ type TranscriptContextAccumulator = {
|
||||
transcriptHasMediaInput: boolean
|
||||
}
|
||||
|
||||
/**
|
||||
* Whether this line's `usage` is the first sighting of its reply.
|
||||
*
|
||||
* Claude Code writes one JSONL line per content block of an assistant message and repeats the
|
||||
* complete `usage` object on every one — a reply with thinking, text and 12 tool_use blocks is
|
||||
* 14 lines carrying the same numbers. Summing raw lines overstated real transcripts by 2.2x,
|
||||
* which is why `stats.ts` and the activity index both deduplicate; the inspector paths had
|
||||
* inherited only the fork check and so reported inflated totals to the context panel.
|
||||
*
|
||||
* Rules (and the key shape) come from `usageAccounting.ts` so every reader of a transcript
|
||||
* agrees about what one session cost.
|
||||
*/
|
||||
function claimUsageRecord(entry: RawEntry, countedKeys: Set<string>): boolean {
|
||||
const record = entry as unknown as Record<string, unknown>
|
||||
const identity = {
|
||||
version: record.version,
|
||||
sessionId: record.sessionId,
|
||||
requestId: record.requestId,
|
||||
messageId: entry.message?.id,
|
||||
forkedFrom: record.forkedFrom,
|
||||
}
|
||||
if (!isBillableUsageRecord(identity)) return false
|
||||
const key = usageRecordKey(identity)
|
||||
if (key === null) return true
|
||||
if (countedKeys.has(key)) return false
|
||||
countedKeys.add(key)
|
||||
return true
|
||||
}
|
||||
|
||||
function createTranscriptContextAccumulator(): TranscriptContextAccumulator {
|
||||
return {
|
||||
latestModel: null,
|
||||
@@ -1727,6 +1771,14 @@ export class SessionService {
|
||||
const usage = isForkInheritedUsageRecord(entry)
|
||||
? undefined
|
||||
: normalizeMessageUsage(msg.usage)
|
||||
const usageKey = usage
|
||||
? usageRecordKey({
|
||||
version: entry.version,
|
||||
sessionId: entry.sessionId,
|
||||
requestId: entry.requestId,
|
||||
messageId: entry.message?.id,
|
||||
}) ?? undefined
|
||||
: undefined
|
||||
|
||||
return {
|
||||
id: entry.uuid || crypto.randomUUID(),
|
||||
@@ -1736,6 +1788,7 @@ export class SessionService {
|
||||
timestamp: entry.timestamp || new Date().toISOString(),
|
||||
model: msg.model,
|
||||
...(usage ? { usage } : {}),
|
||||
...(usageKey ? { usageKey } : {}),
|
||||
parentUuid: entry.parentUuid ?? undefined,
|
||||
parentToolUseId,
|
||||
isSidechain: entry.isSidechain,
|
||||
@@ -2883,9 +2936,13 @@ export class SessionService {
|
||||
let firstUsageAt: number | null = null
|
||||
let lastUsageAt: number | null = null
|
||||
|
||||
const countedUsageKeys = new Set<string>()
|
||||
|
||||
for (const entry of entries) {
|
||||
currentRuntimeHint = this.applyRuntimeContextMetadata(currentRuntimeHint, entry)
|
||||
if (isForkInheritedUsageRecord(entry)) continue
|
||||
// Fork-inherited lines and the repeated usage objects of a multi-block reply are the
|
||||
// same class of over-count; `claimUsageRecord` rejects both.
|
||||
if (!claimUsageRecord(entry, countedUsageKeys)) continue
|
||||
const usage = entry.message?.usage
|
||||
const model = entry.message?.model
|
||||
if (!usage || typeof model !== 'string') continue
|
||||
@@ -3016,6 +3073,7 @@ export class SessionService {
|
||||
let lastUsageAt: number | null = null
|
||||
|
||||
const contextState = createTranscriptContextAccumulator()
|
||||
const countedUsageKeys = new Set<string>()
|
||||
|
||||
await this.streamJsonlFile(found.filePath, (entry) => {
|
||||
if (typeof entry.message?.model === 'string') {
|
||||
@@ -3098,9 +3156,9 @@ export class SessionService {
|
||||
? usage.server_tool_use.web_search_requests
|
||||
: 0
|
||||
|
||||
// Inherited fork history still describes the current context, but its API usage belongs to
|
||||
// the source session and must not be included in this fork's cumulative usage or cost.
|
||||
if (isForkInheritedUsageRecord(entry)) return
|
||||
// Fork-inherited lines and the repeated usage objects of a multi-block reply are the
|
||||
// same class of over-count; `claimUsageRecord` rejects both.
|
||||
if (!claimUsageRecord(entry, countedUsageKeys)) return
|
||||
|
||||
if (
|
||||
inputTokens === 0 &&
|
||||
@@ -3200,6 +3258,11 @@ export class SessionService {
|
||||
costDisplay: this.formatCost(totalCostUSD),
|
||||
hasUnknownModelCost,
|
||||
totalAPIDuration: 0,
|
||||
// Generation timings live only in the CLI process (and the resume snapshot it
|
||||
// writes to project config); a transcript has no per-response span to rebuild
|
||||
// them from, so callers must treat 0 as "unknown" rather than "instant".
|
||||
totalDecodeDuration: 0,
|
||||
totalTtftDuration: 0,
|
||||
totalDuration:
|
||||
firstUsageAt !== null && lastUsageAt !== null
|
||||
? Math.max(0, Math.round((lastUsageAt - firstUsageAt) / 1000))
|
||||
|
||||
+18
-1
@@ -100,7 +100,7 @@ export type ServerMessage =
|
||||
turnActive: boolean
|
||||
}
|
||||
| { type: 'user_message_replay'; content: string }
|
||||
| { type: 'message_complete'; usage: TokenUsage }
|
||||
| { type: 'message_complete'; usage: TokenUsage; timing?: TurnTiming }
|
||||
/**
|
||||
* `text` is a fragment when the CLI streams `thinking_delta`, and a whole block when
|
||||
* it hands over a finished `thinking` block. The client has to concatenate the first
|
||||
@@ -160,6 +160,23 @@ export type TokenUsage = {
|
||||
cache_creation_tokens?: number
|
||||
}
|
||||
|
||||
/**
|
||||
* Generation timings for one turn, in milliseconds.
|
||||
*
|
||||
* `duration_ms` is wall clock and therefore includes tool execution; `duration_api_ms` covers
|
||||
* only the API requests but includes prefill. `decode_ms` is the span over which the model was
|
||||
* actually emitting tokens — it excludes both — and is the right denominator for tokens/sec.
|
||||
* `ttft_ms` is carried so a client can explain the gap between `duration_api_ms` and `decode_ms`.
|
||||
*
|
||||
* Absent when the turn produced no timed stream; never treat a missing value as zero seconds.
|
||||
*/
|
||||
export type TurnTiming = {
|
||||
duration_ms: number
|
||||
duration_api_ms: number
|
||||
ttft_ms: number
|
||||
decode_ms: number
|
||||
}
|
||||
|
||||
export type ChatState = 'idle' | 'thinking' | 'compacting' | 'tool_executing' | 'streaming' | 'permission_pending'
|
||||
|
||||
// 与 CLI 的 streaming_fallback cause 对齐;unknown 兜底未来新增的 cause 值,
|
||||
|
||||
@@ -13,6 +13,7 @@ import type {
|
||||
PermissionMode,
|
||||
ServerMessage,
|
||||
TokenUsage,
|
||||
TurnTiming,
|
||||
} from './events.js'
|
||||
import { RUNTIME_CONFIG_APPLIED_EVENT } from './events.js'
|
||||
import * as os from 'node:os'
|
||||
@@ -493,6 +494,31 @@ function usageNumber(value: unknown): number {
|
||||
return typeof value === 'number' && Number.isFinite(value) ? value : 0
|
||||
}
|
||||
|
||||
/**
|
||||
* Generation timings the CLI reports on its `result` message.
|
||||
*
|
||||
* These used to be dropped here, which is why nothing downstream could say how fast tokens were
|
||||
* being produced. `decode_ms` is the one that matters: it spans only the time the model spent
|
||||
* emitting tokens, so `output_tokens / decode_ms` is a rate rather than a number diluted by
|
||||
* prefill and tool execution. All four are 0/absent together when the turn produced no timed
|
||||
* stream (non-streaming fallback, or a CLI too old to report them).
|
||||
*/
|
||||
function translateCliTiming(cliMsg: Record<string, unknown>): TurnTiming | undefined {
|
||||
const durationMs = usageNumber(cliMsg.duration_ms)
|
||||
const durationApiMs = usageNumber(cliMsg.duration_api_ms)
|
||||
const decodeMs = usageNumber(cliMsg.decode_ms)
|
||||
const ttftMs = usageNumber(cliMsg.ttft_ms)
|
||||
if (durationMs === 0 && durationApiMs === 0 && decodeMs === 0 && ttftMs === 0) {
|
||||
return undefined
|
||||
}
|
||||
return {
|
||||
duration_ms: durationMs,
|
||||
duration_api_ms: durationApiMs,
|
||||
ttft_ms: ttftMs,
|
||||
decode_ms: decodeMs,
|
||||
}
|
||||
}
|
||||
|
||||
function translateCliUsage(usage: unknown): TokenUsage {
|
||||
const record = usage && typeof usage === 'object'
|
||||
? usage as Record<string, unknown>
|
||||
@@ -3235,6 +3261,7 @@ export function translateCliMessage(cliMsg: any, sessionId: string): ServerMessa
|
||||
case 'result': {
|
||||
// 对话结果(成功或错误)
|
||||
const usage = translateCliUsage(cliMsg.usage)
|
||||
const timing = translateCliTiming(cliMsg)
|
||||
// Buffered assistant blocks can arrive as a batch after all raw events
|
||||
// for one provider message. Keep deduplication active across the entire
|
||||
// batch, then clear it only at the terminal result boundary.
|
||||
@@ -3243,11 +3270,13 @@ export function translateCliMessage(cliMsg: any, sessionId: string): ServerMessa
|
||||
if (cliMsg.is_error) {
|
||||
// If the user requested stop, this "error" is just the interrupt
|
||||
// result — don't show it as an error in the chat UI.
|
||||
// Timing survives an interrupt: the tokens really were generated and paid for,
|
||||
// and a cancelled turn is exactly when a client wants to know what it cost.
|
||||
if (
|
||||
interruptedTurnResultMessages.get(cliMsg) === sessionId ||
|
||||
sessionStopRequested.has(sessionId)
|
||||
) {
|
||||
return [{ type: 'message_complete', usage }]
|
||||
return [{ type: 'message_complete', usage, ...(timing ? { timing } : {}) }]
|
||||
}
|
||||
|
||||
const resultMessage =
|
||||
@@ -3257,7 +3286,7 @@ export function translateCliMessage(cliMsg: any, sessionId: string): ServerMessa
|
||||
: 'Unknown error')
|
||||
if (isDuplicateOfLastApiError(streamState.lastApiError, resultMessage)) {
|
||||
streamState.lastApiError = undefined
|
||||
return [{ type: 'message_complete', usage }]
|
||||
return [{ type: 'message_complete', usage, ...(timing ? { timing } : {}) }]
|
||||
}
|
||||
// 错误和完成消息都发送
|
||||
return [
|
||||
@@ -3266,12 +3295,12 @@ export function translateCliMessage(cliMsg: any, sessionId: string): ServerMessa
|
||||
message: resultMessage,
|
||||
code: classifyRuntimeErrorCode(resultMessage, 'CLI_ERROR'),
|
||||
},
|
||||
{ type: 'message_complete', usage },
|
||||
{ type: 'message_complete', usage, ...(timing ? { timing } : {}) },
|
||||
]
|
||||
}
|
||||
|
||||
streamState.lastApiError = undefined
|
||||
return [{ type: 'message_complete', usage }]
|
||||
return [{ type: 'message_complete', usage, ...(timing ? { timing } : {}) }]
|
||||
}
|
||||
|
||||
case 'system': {
|
||||
|
||||
@@ -237,6 +237,7 @@ import {
|
||||
StreamWatchdogTimeoutError,
|
||||
createStreamWatchdogState,
|
||||
} from "./streamWatchdog.js";
|
||||
import { StreamDecodeSpan } from "./streamDecodeSpan.js";
|
||||
import { jsonStringify } from "../../utils/slowOperations.js";
|
||||
import {
|
||||
isBetaTracingEnabled,
|
||||
@@ -1957,6 +1958,11 @@ async function* queryModel(
|
||||
deferToolUseCommit: true,
|
||||
});
|
||||
let ttftMs = 0;
|
||||
// Decode span for this request: first generated delta -> message_stop. Deliberately excludes
|
||||
// the prefill/TTFT phase, so output_tokens / decodeMs is real generation speed rather than a
|
||||
// number diluted by prompt processing. Tool execution happens between API requests, so it
|
||||
// never lands inside this span either.
|
||||
const decodeSpan = new StreamDecodeSpan();
|
||||
let partialMessage: BetaMessage | undefined = undefined;
|
||||
const contentBlocks: (BetaContentBlock | ConnectorTextBlock)[] = [];
|
||||
let usage: NonNullableUsage = EMPTY_USAGE;
|
||||
@@ -2059,6 +2065,7 @@ async function* queryModel(
|
||||
// reset state
|
||||
newMessages.length = 0;
|
||||
ttftMs = 0;
|
||||
decodeSpan.reset();
|
||||
partialMessage = undefined;
|
||||
contentBlocks.length = 0;
|
||||
usage = EMPTY_USAGE;
|
||||
@@ -2265,6 +2272,8 @@ async function* queryModel(
|
||||
resetStreamIdleTimer();
|
||||
const now = Date.now();
|
||||
|
||||
decodeSpan.record(receivedFirstContentDelta, now);
|
||||
|
||||
// Detect and log streaming stalls (only after first event to avoid counting TTFB)
|
||||
if (lastEventTime !== null) {
|
||||
const timeSinceLastEvent = now - lastEventTime;
|
||||
@@ -2660,6 +2669,11 @@ async function* queryModel(
|
||||
type: "stream_event",
|
||||
event: part,
|
||||
...(part.type === "message_start" ? { ttftMs } : undefined),
|
||||
// message_stop is the last event of the stream, so `now` closes the decode span.
|
||||
// Absent when the span never opened (see StreamDecodeSpan).
|
||||
...(part.type === "message_stop"
|
||||
? { decodeMs: decodeSpan.elapsedMs(now) }
|
||||
: undefined),
|
||||
};
|
||||
}
|
||||
// Clear the idle timeout watchdog now that the stream loop has exited
|
||||
|
||||
@@ -0,0 +1,63 @@
|
||||
import { describe, expect, test } from 'bun:test'
|
||||
import { StreamDecodeSpan } from './streamDecodeSpan.js'
|
||||
|
||||
describe('StreamDecodeSpan', () => {
|
||||
test('measures from the first generated delta, not from request start', () => {
|
||||
const span = new StreamDecodeSpan()
|
||||
|
||||
// 2s of prefill: message_start and bookkeeping arrive, no token has been generated yet.
|
||||
span.record(false, 1_000)
|
||||
span.record(false, 1_200)
|
||||
span.record(false, 2_000)
|
||||
expect(span.elapsedMs(2_000)).toBe(0)
|
||||
|
||||
// First real token at 2s; generation runs until the stream closes at 7s.
|
||||
span.record(true, 2_000)
|
||||
span.record(false, 5_000)
|
||||
expect(span.elapsedMs(7_000)).toBe(5_000)
|
||||
})
|
||||
|
||||
test('does not reopen the span on later content deltas', () => {
|
||||
const span = new StreamDecodeSpan()
|
||||
|
||||
span.record(true, 1_000)
|
||||
// The watchdog flag only fires once, but a caller that passed it twice must not restart
|
||||
// the clock — that would report a speed for the last token alone.
|
||||
span.record(true, 4_000)
|
||||
span.record(true, 6_000)
|
||||
|
||||
expect(span.elapsedMs(9_000)).toBe(8_000)
|
||||
})
|
||||
|
||||
test('reports nothing for a stream that never generated a token', () => {
|
||||
const span = new StreamDecodeSpan()
|
||||
|
||||
span.record(false, 1_000)
|
||||
span.record(false, 9_000)
|
||||
|
||||
// A request that produced no content has no rate to report. Returning the wait would let a
|
||||
// caller divide output tokens by a prefill-only span.
|
||||
expect(span.elapsedMs(9_000)).toBe(0)
|
||||
})
|
||||
|
||||
test('reset clears the span for a retried attempt', () => {
|
||||
const span = new StreamDecodeSpan()
|
||||
span.record(true, 1_000)
|
||||
expect(span.elapsedMs(4_000)).toBe(3_000)
|
||||
|
||||
span.reset()
|
||||
|
||||
// The second attempt's prefill must not be counted as generation time from the first.
|
||||
span.record(false, 10_000)
|
||||
expect(span.elapsedMs(10_000)).toBe(0)
|
||||
span.record(true, 12_000)
|
||||
expect(span.elapsedMs(15_000)).toBe(3_000)
|
||||
})
|
||||
|
||||
test('never returns a negative span when the clock steps backwards', () => {
|
||||
const span = new StreamDecodeSpan()
|
||||
span.record(true, 5_000)
|
||||
|
||||
expect(span.elapsedMs(4_000)).toBe(0)
|
||||
})
|
||||
})
|
||||
@@ -0,0 +1,38 @@
|
||||
/**
|
||||
* Tracks the span over which a single API response was emitting tokens.
|
||||
*
|
||||
* Tokens/sec is only meaningful as `output_tokens / decode_ms` when the denominator excludes the
|
||||
* prefill wait and every tool round-trip. So the span opens at the first *generated* delta rather
|
||||
* than at request start, and it closes when the stream terminates — the same measurement the
|
||||
* session projections make host-side in DeepSeek Harness.
|
||||
*
|
||||
* A stream that ends without `message_stop` reports 0, meaning "unknown", not "instant": the
|
||||
* response was truncated, and a partial span would both understate the rate the model was
|
||||
* actually running at and invite a caller to divide by a number that describes nothing.
|
||||
*/
|
||||
export class StreamDecodeSpan {
|
||||
private firstContentDeltaAt: number | null = null
|
||||
|
||||
/** Call at the top of each attempt — a retried request starts a fresh span. */
|
||||
reset(): void {
|
||||
this.firstContentDeltaAt = null
|
||||
}
|
||||
|
||||
/**
|
||||
* Record one stream event.
|
||||
*
|
||||
* `isFirstContentDelta` is the watchdog's transition flag, which is exactly "the first token
|
||||
* was generated"; the span needs no inspection of its own.
|
||||
*/
|
||||
record(isFirstContentDelta: boolean, now: number): void {
|
||||
if (isFirstContentDelta && this.firstContentDeltaAt === null) {
|
||||
this.firstContentDeltaAt = now
|
||||
}
|
||||
}
|
||||
|
||||
/** Milliseconds since the first generated delta, or 0 when no span ever opened. */
|
||||
elapsedMs(now: number): number {
|
||||
if (this.firstContentDeltaAt === null) return 0
|
||||
return Math.max(0, now - this.firstContentDeltaAt)
|
||||
}
|
||||
}
|
||||
@@ -79,6 +79,8 @@ export type ProjectConfig = {
|
||||
mcpServers?: Record<string, McpServerConfig>
|
||||
lastAPIDuration?: number
|
||||
lastAPIDurationWithoutRetries?: number
|
||||
lastDecodeDuration?: number
|
||||
lastTtftDuration?: number
|
||||
lastToolDuration?: number
|
||||
lastCost?: number
|
||||
lastDuration?: number
|
||||
|
||||
Reference in New Issue
Block a user