From a3578aae56d742ace791e6b9329fde02904a5712 Mon Sep 17 00:00:00 2001 From: JUN Date: Thu, 10 Sep 2026 09:02:33 +0900 Subject: [PATCH 1/3] feat(logs): show an estimated decode rate alongside end-to-end throughput Logs reported one rate. tokensPerSecond() never subtracted TTFT, tokPerSecondResult passed the full duration, and the MetricSource Pick did not even include firstOutputMs, so a decode-rate metric could not be computed at all -- even though TTFT is already recorded per request and per combo attempt. It was never a calculation bug: the end-to-end metric is documented as end-to-end. It is a missing metric. The history is why this is not a straight re-land. Contributor PR #4040 implemented the same metric and was closed unmerged by the reporter, on the grounds that proxy TTFT and the provider's own generation window do not line up and that a small post-TTFT remainder makes the estimate explode. The issue stayed open, so the repository held both an acceptance criterion and a rejection of the same feature. MIN_DECODE_WINDOW_MS answers the rejection directly. Below one second the window is dominated by TTFT jitter, proxy buffering and timestamp granularity, so a window under the floor yields NO value instead of a four-digit number. The second half of the answer is honesty rather than arithmetic: the value is always marked estimated, because proxy TTFT is when the first byte reached the proxy and no window length makes that the provider's generation start. Strictly additive. tokensPerSecond, tokPerSecondResult, filterLogs, RequestLogEntry and usage.jsonl are untouched, the end-to-end rate keeps its meaning, the speed filter still sorts on it, and this stays out of /api/request-history. The parent uses the request's own TTFT and each attempt uses its own attempt-relative one; a combo parent never borrows a child's. Closes #4038. --- gui/src/i18n/de.ts | 3 + gui/src/i18n/en.ts | 3 + gui/src/i18n/fr.ts | 3 + gui/src/i18n/ja.ts | 3 + gui/src/i18n/ko.ts | 3 + gui/src/i18n/ru.ts | 3 + gui/src/i18n/tr.ts | 3 + gui/src/i18n/zh-TW.ts | 3 + gui/src/i18n/zh.ts | 3 + gui/src/pages/Logs.tsx | 26 +++- src/server/management/shared.ts | 55 +++++++- .../management-api-logs-metrics.test.ts | 129 ++++++++++++++++++ 12 files changed, 234 insertions(+), 3 deletions(-) diff --git a/gui/src/i18n/de.ts b/gui/src/i18n/de.ts index b92691411a..53a3b781a3 100644 --- a/gui/src/i18n/de.ts +++ b/gui/src/i18n/de.ts @@ -764,6 +764,9 @@ export const de: Record = { "logs.detail.section.attempts": "Combo-Versuche", "logs.detail.section.usage": "Roh-Nutzung", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "Dekodierrate (geschätzt)", + "logs.detail.reason.ttft_missing": "Für diese Anfrage wurde keine Zeit bis zum ersten Token erfasst, es gibt also kein Dekodierfenster zum Messen.", + "logs.detail.reason.decode_window_too_short": "Das Fenster nach dem ersten Token lag unter einer Sekunde und ist zu kurz für eine Schätzung der Dekodierrate.", "logs.detail.costTotal": "Listenpreis-Äquivalent", "logs.detail.totalTokens": "Tokens gesamt", "logs.detail.matchedKey": "Zugeordneter Preisschlüssel", diff --git a/gui/src/i18n/en.ts b/gui/src/i18n/en.ts index a8f6cf20a0..df1483af54 100644 --- a/gui/src/i18n/en.ts +++ b/gui/src/i18n/en.ts @@ -813,6 +813,9 @@ export const en = { "logs.detail.section.attempts": "Combo attempts", "logs.detail.section.usage": "Raw usage", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "Decode rate (est.)", + "logs.detail.reason.ttft_missing": "No time-to-first-token was recorded for this request, so there is no decode window to measure.", + "logs.detail.reason.decode_window_too_short": "The window after the first token was under a second, which is too short to estimate a decode rate from.", "logs.detail.costTotal": "List-price equivalent", "logs.detail.totalTokens": "Total tokens", "logs.detail.matchedKey": "Matched price key", diff --git a/gui/src/i18n/fr.ts b/gui/src/i18n/fr.ts index 855a8a146f..302cc262f0 100644 --- a/gui/src/i18n/fr.ts +++ b/gui/src/i18n/fr.ts @@ -794,6 +794,9 @@ export const fr: Record = { "logs.detail.section.attempts": "Tentatives de combinaison", "logs.detail.section.usage": "Utilisation brute", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "Débit de décodage (est.)", + "logs.detail.reason.ttft_missing": "Aucun délai jusqu’au premier token n’a été enregistré pour cette requête, il n’y a donc pas de fenêtre de décodage à mesurer.", + "logs.detail.reason.decode_window_too_short": "La fenêtre après le premier token durait moins d’une seconde, ce qui est trop court pour estimer un débit de décodage.", "logs.detail.costTotal": "Équivalent au tarif catalogue", "logs.detail.totalTokens": "Nombre total de jetons", "logs.detail.matchedKey": "Clé de tarif correspondante", diff --git a/gui/src/i18n/ja.ts b/gui/src/i18n/ja.ts index be78373e77..4cf39e050d 100644 --- a/gui/src/i18n/ja.ts +++ b/gui/src/i18n/ja.ts @@ -726,6 +726,9 @@ export const ja: Record = { "logs.detail.section.attempts": "コンボの試行", "logs.detail.section.usage": "生の使用量", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "デコード速度（推定）", + "logs.detail.reason.ttft_missing": "このリクエストでは最初のトークンまでの時間が記録されていないため、測定できるデコード区間がありません。", + "logs.detail.reason.decode_window_too_short": "最初のトークン以降の区間が1秒未満で、デコード速度を推定するには短すぎます。", "logs.detail.costTotal": "定価相当額", "logs.detail.totalTokens": "合計トークン", "logs.detail.matchedKey": "一致した価格キー", diff --git a/gui/src/i18n/ko.ts b/gui/src/i18n/ko.ts index 49b3b4f203..c1d95d0946 100644 --- a/gui/src/i18n/ko.ts +++ b/gui/src/i18n/ko.ts @@ -795,6 +795,9 @@ export const ko: Record = { "logs.detail.section.attempts": "Combo 시도", "logs.detail.section.usage": "원본 usage", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "디코드 속도(추정)", + "logs.detail.reason.ttft_missing": "이 요청은 첫 토큰까지 걸린 시간이 기록되지 않아서 측정할 디코드 구간이 없어요.", + "logs.detail.reason.decode_window_too_short": "첫 토큰 이후 구간이 1초도 안 돼서 디코드 속도를 추정하기엔 너무 짧아요.", "logs.detail.costTotal": "정가 환산치", "logs.detail.totalTokens": "전체 토큰", "logs.detail.matchedKey": "매칭된 가격 키", diff --git a/gui/src/i18n/ru.ts b/gui/src/i18n/ru.ts index 72df6bb9db..3fa4777c28 100644 --- a/gui/src/i18n/ru.ts +++ b/gui/src/i18n/ru.ts @@ -781,6 +781,9 @@ export const ru: Record = { "logs.detail.section.attempts": "Попытки комбо", "logs.detail.section.usage": "Сырые данные использования", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "Скорость декодирования (оценка)", + "logs.detail.reason.ttft_missing": "Для этого запроса не записано время до первого токена, поэтому измерять нечего.", + "logs.detail.reason.decode_window_too_short": "Окно после первого токена длилось меньше секунды — слишком мало для оценки скорости декодирования.", "logs.detail.costTotal": "Эквивалент по прайс-листу", "logs.detail.totalTokens": "Всего токенов", "logs.detail.matchedKey": "Совпавший ключ цены", diff --git a/gui/src/i18n/tr.ts b/gui/src/i18n/tr.ts index da99115c81..ccea8e9f64 100644 --- a/gui/src/i18n/tr.ts +++ b/gui/src/i18n/tr.ts @@ -800,6 +800,9 @@ export const tr: Record = { "logs.detail.section.attempts": "Kombo denemeleri", "logs.detail.section.usage": "Ham kullanım", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "Çözme hızı (tahmini)", + "logs.detail.reason.ttft_missing": "Bu istek için ilk token süresi kaydedilmediğinden ölçülecek bir çözme aralığı yok.", + "logs.detail.reason.decode_window_too_short": "İlk token sonrasındaki aralık bir saniyenin altındaydı; çözme hızını tahmin etmek için fazla kısa.", "logs.detail.costTotal": "Liste fiyatı eşdeğeri", "logs.detail.totalTokens": "Toplam jeton", "logs.detail.matchedKey": "Eşleşen anahtar", diff --git a/gui/src/i18n/zh-TW.ts b/gui/src/i18n/zh-TW.ts index 7f5f06a770..37b59e8199 100644 --- a/gui/src/i18n/zh-TW.ts +++ b/gui/src/i18n/zh-TW.ts @@ -624,6 +624,9 @@ export const zhTW: Record = { "logs.detail.section.attempts": "Combo 嘗試", "logs.detail.section.usage": "原始 usage", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "解碼速率（估算）", + "logs.detail.reason.ttft_missing": "此請求沒有記錄第一個 token 的時間，因此沒有可測量的解碼區間。", + "logs.detail.reason.decode_window_too_short": "第一個 token 之後的區間不到一秒，太短，無法估算解碼速率。", "logs.detail.costTotal": "標價折算", "logs.detail.totalTokens": "Token 總數", "logs.detail.matchedKey": "符合的 jawcode 鍵", diff --git a/gui/src/i18n/zh.ts b/gui/src/i18n/zh.ts index 628f458030..c869e72dce 100644 --- a/gui/src/i18n/zh.ts +++ b/gui/src/i18n/zh.ts @@ -776,6 +776,9 @@ export const zh: Record = { "logs.detail.section.attempts": "Combo 尝试", "logs.detail.section.usage": "原始 usage", "logs.detail.ttft": "TTFT", + "logs.detail.decodeTokPerSec": "解码速率（估算）", + "logs.detail.reason.ttft_missing": "该请求没有记录首个 token 的时间，因此没有可测量的解码区间。", + "logs.detail.reason.decode_window_too_short": "首个 token 之后的区间不足一秒，太短，无法估算解码速率。", "logs.detail.costTotal": "标价折算", "logs.detail.totalTokens": "Token 总数", "logs.detail.matchedKey": "匹配的价格键", diff --git a/gui/src/pages/Logs.tsx b/gui/src/pages/Logs.tsx index 03a0a45005..a2be1bf298 100644 --- a/gui/src/pages/Logs.tsx +++ b/gui/src/pages/Logs.tsx @@ -53,7 +53,8 @@ type LogUsageStatus = "reported" | "unreported" | "unsupported" | "estimated"; type MetricUnavailableReason = | "usage_missing" | "usage_unsupported" | "output_missing" | "invalid_duration" | "price_unmatched" | "invalid_cache_breakdown" - | "invalid_usage" | "combo_attempt_unavailable"; + | "invalid_usage" | "combo_attempt_unavailable" + | "ttft_missing" | "decode_window_too_short"; type CostEstimateReason = | "usage_estimated" @@ -92,6 +93,11 @@ type CostResult = interface LogDisplayMetrics { tokPerSecond: TokPerSecondResult; + /** + * Estimated decode throughput (#4038). Optional because a row cached by an older build has no + * such field; absent renders nothing rather than an empty slot. + */ + decodeTokPerSecond?: TokPerSecondResult; cost: CostResult; } @@ -276,6 +282,8 @@ const METRIC_REASON_KEYS = { invalid_cache_breakdown: "logs.detail.reason.invalid_cache_breakdown", invalid_usage: "logs.detail.reason.invalid_usage", combo_attempt_unavailable: "logs.detail.reason.combo_attempt_unavailable", + ttft_missing: "logs.detail.reason.ttft_missing", + decode_window_too_short: "logs.detail.reason.decode_window_too_short", } as const satisfies Record; const ESTIMATE_REASON_KEYS = { @@ -814,6 +822,14 @@ export default function Logs({ apiBase }: { apiBase: string }) { {formatTokPerSecond(log.displayMetrics?.tokPerSecond, localeTag)} + {/* #4038: decode rate stacked under the end-to-end rate it is easy to mistake + for delivery speed. Only rendered when it actually resolved — a row whose + decode window was too short shows the e2e rate alone rather than a blank. */} + {log.displayMetrics?.decodeTokPerSecond?.kind === "value" && ( + + {formatTokPerSecond(log.displayMetrics.decodeTokPerSecond, localeTag)} + + )} {formatEstimatedUsd(log.displayMetrics?.cost, t, localeTag)} @@ -1033,6 +1049,9 @@ function LogDetailDialog({
{t("logs.col.duration")}{detail.durationMs}ms {t("logs.col.tokPerSec")}{formatTokPerSecond(detail.displayMetrics?.tokPerSecond, localeTag)} + {detail.displayMetrics?.decodeTokPerSecond?.kind === "value" && ( + <>{t("logs.detail.decodeTokPerSec")}{formatTokPerSecond(detail.displayMetrics.decodeTokPerSecond, localeTag)} + )} {detail.firstOutputMs !== undefined && ( <>{t("logs.detail.ttft")}{detail.firstOutputMs}ms )} @@ -1040,6 +1059,11 @@ function LogDetailDialog({ {detail.displayMetrics?.tokPerSecond.kind === "unavailable" && (

{t(metricReasonKey(detail.displayMetrics.tokPerSecond.reason))}

)} + {detail.displayMetrics?.decodeTokPerSecond?.kind === "unavailable" && ( +

+ {t("logs.detail.decodeTokPerSec")}: {t(metricReasonKey(detail.displayMetrics.decodeTokPerSecond.reason))} +

+ )}
diff --git a/src/server/management/shared.ts b/src/server/management/shared.ts index 6591bddd1b..7ed7c14b7e 100644 --- a/src/server/management/shared.ts +++ b/src/server/management/shared.ts @@ -79,7 +79,8 @@ export function parseDebugLogQuery(url: URL): { after: number; limit: number } { export type MetricUnavailableReason = | "usage_missing" | "usage_unsupported" | "output_missing" | "invalid_duration" | "price_unmatched" | "invalid_cache_breakdown" - | "invalid_usage" | "combo_attempt_unavailable"; + | "invalid_usage" | "combo_attempt_unavailable" + | "ttft_missing" | "decode_window_too_short"; export type TokPerSecondResult = | { kind: "value"; value: number; estimated: boolean } @@ -96,7 +97,7 @@ export type CostResult = | { kind: "value"; estimate: NonNullable>; estimateReasons: CostEstimateReason[] } | { kind: "unavailable"; reason: MetricUnavailableReason }; -export type MetricSource = Pick & { +export type MetricSource = Pick & { attempts?: readonly PersistedUsageAttempt[]; }; @@ -113,6 +114,51 @@ export function tokPerSecondResult(entry: Pick, +): TokPerSecondResult { + if (!entry.usage) return { kind: "unavailable", reason: "usage_missing" }; + if (entry.usageStatus === "unsupported") return { kind: "unavailable", reason: "usage_unsupported" }; + if (entry.usage.outputTokens <= 0) return { kind: "unavailable", reason: "output_missing" }; + // A row that predates TTFT capture, or a non-streaming turn that never recorded one, has no + // window to measure. That is a different fact from a bad duration, so it gets its own reason. + if (entry.firstOutputMs === undefined) return { kind: "unavailable", reason: "ttft_missing" }; + if (!Number.isFinite(entry.firstOutputMs) || entry.firstOutputMs < 0 || !Number.isFinite(entry.durationMs)) { + return { kind: "unavailable", reason: "invalid_duration" }; + } + const windowMs = entry.durationMs - entry.firstOutputMs; + // TTFT at or past the total duration means the two clocks disagree; there is no window. + if (windowMs <= 0) return { kind: "unavailable", reason: "invalid_duration" }; + if (windowMs < MIN_DECODE_WINDOW_MS) return { kind: "unavailable", reason: "decode_window_too_short" }; + const value = tokensPerSecond(entry.usage.outputTokens, windowMs); + if (value === null) return { kind: "unavailable", reason: "invalid_duration" }; + return { kind: "value", value, estimated: true }; +} + export function unavailableCostReason(entry: MetricSource): MetricUnavailableReason { // Normalizer-first classification: the landed normalizer recovers legacy // cachedInputTokens=read+write rows via retry, so a raw read+write>input @@ -157,6 +203,9 @@ export function requestLogDto(entry: RequestLogEntry): Record { ...entry, displayMetrics: { tokPerSecond: tokPerSecondResult(entry), + // The parent uses the REQUEST's own TTFT. A combo parent must not borrow an attempt's, + // which would measure a window the parent never had. + decodeTokPerSecond: decodeTokPerSecondResult(entry), cost: costResult(entry), }, ...(entry.attempts?.length @@ -165,6 +214,8 @@ export function requestLogDto(entry: RequestLogEntry): Record { ...attempt, displayMetrics: { tokPerSecond: tokPerSecondResult(attempt), + // Each attempt measures its own attempt-relative TTFT. + decodeTokPerSecond: decodeTokPerSecondResult(attempt), cost: costResult({ ...attempt, attempts: undefined, routeDecision: entry.routeDecision, requestedServiceTier: entry.requestedServiceTier, configuredServiceTier: entry.configuredServiceTier, responseServiceTier: entry.responseServiceTier }), }, })), diff --git a/tests/server/management-api-logs-metrics.test.ts b/tests/server/management-api-logs-metrics.test.ts index f13bb3700b..3bdd37800a 100644 --- a/tests/server/management-api-logs-metrics.test.ts +++ b/tests/server/management-api-logs-metrics.test.ts @@ -469,3 +469,132 @@ describe("GET /api/logs account identity", () => { expect((await readLogPoll("account=p000000")).logs).toEqual([]); }); }); + +/** + * #4038 — Logs showed one rate that conflates first-token latency with delivery speed. + * `tokensPerSecond` never subtracted TTFT, and the MetricSource Pick did not even include + * `firstOutputMs`, so a decode-rate metric could not be computed at all. + * + * The history matters more than the arithmetic here. Contributor PR #4040 implemented this exact + * metric and was closed unmerged as an unreliable estimate: proxy TTFT is not the provider's + * generation window, and a small post-TTFT remainder makes the number explode. The issue stayed + * open, so the repository held both an acceptance criterion and a rejection of the same feature. + * + * MIN_DECODE_WINDOW_MS is what answers that rejection, and + * "a decode window under the floor yields no value" is the assertion that proves it. Everything + * else here is scaffolding around that one case. + */ +describe("estimated decode rate (#4038)", () => { + test("subtracts TTFT, and leaves the end-to-end rate exactly as it was", async () => { + addRequestLog(baseEntry({ + durationMs: 10_000, + firstOutputMs: 2_000, + usage: { inputTokens: 1000, outputTokens: 240 }, + })); + const [dto] = await readLogs(); + // 240 tokens over the 8s AFTER the first token. + expect(dto!.displayMetrics.decodeTokPerSecond).toEqual({ kind: "value", value: 30, estimated: true }); + // The e2e rate still divides by the whole 10s: 24. This metric is additive, not a correction. + expect(dto!.displayMetrics.tokPerSecond).toEqual({ kind: "value", value: 24, estimated: false }); + // Derived at response time only, exactly like the metrics beside it. + expect(Object.hasOwn(getRequestLogEntries()[0]!, "displayMetrics")).toBe(false); + }); + + test("is always marked estimated, even on a long, clean window", async () => { + // Proxy TTFT is when the first byte reached the PROXY, never the provider's generation + // start, so no window length makes this an exact measurement. + addRequestLog(baseEntry({ + durationMs: 60_000, + firstOutputMs: 1_000, + usage: { inputTokens: 10, outputTokens: 5900, estimated: false }, + })); + const [dto] = await readLogs(); + expect(dto!.displayMetrics.decodeTokPerSecond.kind).toBe("value"); + expect(dto!.displayMetrics.decodeTokPerSecond.estimated).toBe(true); + }); + + test("a decode window under the floor yields no value rather than an absurd rate", async () => { + // THE #4040 case. 240 tokens over a 50 ms remainder is 4800 tok/s, which is not a fact about + // the model; it is a fact about clock granularity and proxy buffering. Refusing to print it + // is the whole point of the guard. + addRequestLog(baseEntry({ + durationMs: 10_000, + firstOutputMs: 9_950, + usage: { inputTokens: 1000, outputTokens: 240 }, + })); + const [dto] = await readLogs(); + expect(dto!.displayMetrics.decodeTokPerSecond).toEqual({ + kind: "unavailable", + reason: "decode_window_too_short", + }); + expect(JSON.stringify(dto!.displayMetrics.decodeTokPerSecond)).not.toContain("4800"); + // The end-to-end rate is unaffected and still reported. + expect(dto!.displayMetrics.tokPerSecond.kind).toBe("value"); + }); + + test("a missing TTFT is its own reason, not a bad duration", async () => { + addRequestLog(baseEntry({ + durationMs: 10_000, + usage: { inputTokens: 1000, outputTokens: 240 }, + })); + const [dto] = await readLogs(); + expect(dto!.displayMetrics.decodeTokPerSecond).toEqual({ kind: "unavailable", reason: "ttft_missing" }); + }); + + test("a TTFT at or past the total duration is an invalid duration", async () => { + for (const firstOutputMs of [10_000, 12_000]) { + clearRequestLogsForTests(); + addRequestLog(baseEntry({ + durationMs: 10_000, + firstOutputMs, + usage: { inputTokens: 1000, outputTokens: 240 }, + })); + const [dto] = await readLogs(); + expect(dto!.displayMetrics.decodeTokPerSecond).toEqual({ kind: "unavailable", reason: "invalid_duration" }); + } + }); + + test("no output tokens is output_missing, and unsupported usage stays unsupported", async () => { + clearRequestLogsForTests(); + addRequestLog(baseEntry({ + durationMs: 10_000, + firstOutputMs: 1_000, + usage: { inputTokens: 1000, outputTokens: 0 }, + })); + expect((await readLogs())[0]!.displayMetrics.decodeTokPerSecond) + .toEqual({ kind: "unavailable", reason: "output_missing" }); + + clearRequestLogsForTests(); + addRequestLog(baseEntry({ + durationMs: 10_000, + firstOutputMs: 1_000, + usageStatus: "unsupported", + usage: { inputTokens: 1000, outputTokens: 240 }, + })); + expect((await readLogs())[0]!.displayMetrics.decodeTokPerSecond) + .toEqual({ kind: "unavailable", reason: "usage_unsupported" }); + }); + + test("each attempt measures its own window; the parent never borrows one", async () => { + // requestLogDto maps attempts separately on purpose. Copying a child's firstOutputMs onto the + // parent would report a window the parent never had. + clearRequestLogsForTests(); + addRequestLog(baseEntry({ + durationMs: 20_000, + usage: { inputTokens: 10, outputTokens: 400 }, + attempts: [{ + provider: "anthropic", + model: "claude-3-haiku-20240307", + durationMs: 10_000, + firstOutputMs: 2_000, + usageStatus: "reported", + usage: { inputTokens: 10, outputTokens: 240 }, + }], + } as Partial)); + const [dto] = await readLogs(); + // The parent has no TTFT of its own, so it reports none rather than the attempt's. + expect(dto!.displayMetrics.decodeTokPerSecond).toEqual({ kind: "unavailable", reason: "ttft_missing" }); + expect(dto!.attempts[0].displayMetrics.decodeTokPerSecond) + .toEqual({ kind: "value", value: 30, estimated: true }); + }); +}); From b19fa9e354da55f47acc7a6861821846e8497ec3 Mon Sep 17 00:00:00 2001 From: JUN Date: Thu, 10 Sep 2026 09:34:32 +0900 Subject: [PATCH 2/3] fix(logs): render the decode rate on attempts and keep it out of request history Two gaps. The attempt table still showed only the end-to-end rate, while the parent detail and the list stacked both. The DTO already carried a per-attempt decode rate measured on that attempt's own TTFT, so this was a rendering gap rather than a data one. /api/request-history shares requestLogDto but not its contract, and the field was riding along. requestLogDto now takes includeDecodeRate, defaulting to true so /api/logs is unchanged, and both history call sites opt out. Worth stating plainly: the value would have been MEANINGFUL there, not noise -- firstOutputMs does survive into a persisted-usage row, so history entries would have carried real numbers. The exclusion is therefore a scope decision rather than a correctness one. The decode rate is a Logs-page metric, and widening a separate endpoint's response shape is not this change's business. Flipping it on later is one argument. Both halves are asserted: the DTO omits the field on parent and attempts under the opt-out while keeping tok/s and cost, the default still includes it, and a source check pins that the route passes the flag at every call site -- otherwise a correct flag and a route that never set it would both look fine. --- gui/src/pages/Logs.tsx | 12 +++++- .../management/request-history-routes.ts | 6 ++- src/server/management/shared.ts | 18 ++++++-- .../management-api-logs-metrics.test.ts | 41 +++++++++++++++++++ 4 files changed, 71 insertions(+), 6 deletions(-) diff --git a/gui/src/pages/Logs.tsx b/gui/src/pages/Logs.tsx index a2be1bf298..774efc455a 100644 --- a/gui/src/pages/Logs.tsx +++ b/gui/src/pages/Logs.tsx @@ -1148,7 +1148,17 @@ function LogDetailDialog({ )} {attempt.durationMs}ms - {formatTokPerSecond(attempt.displayMetrics?.tokPerSecond, localeTag)} + + {formatTokPerSecond(attempt.displayMetrics?.tokPerSecond, localeTag)} + {/* #4038: the DTO already carries a per-attempt decode rate measured on + that attempt's own TTFT, so the attempt table stacks it the same way + the parent row and the list do. */} + {attempt.displayMetrics?.decodeTokPerSecond?.kind === "value" && ( + + {formatTokPerSecond(attempt.displayMetrics.decodeTokPerSecond, localeTag)} + + )} + {formatEstimatedUsd(attemptCost, t, localeTag)} {reason} diff --git a/src/server/management/request-history-routes.ts b/src/server/management/request-history-routes.ts index 0af7e860c9..fd9df76550 100644 --- a/src/server/management/request-history-routes.ts +++ b/src/server/management/request-history-routes.ts @@ -106,7 +106,9 @@ export async function handleRequestHistoryRoutes(ctx: ManagementContext): Promis to, }, cursor, limit); return jsonResponse({ - entries: page.rows.map(row => requestLogDto(requestLogEntryFromPersistedUsage(row))), + // The decode rate is a Logs-page metric; this endpoint shares the DTO but not its + // contract, so it opts out rather than silently widening its own response shape (#4038). + entries: page.rows.map(row => requestLogDto(requestLogEntryFromPersistedUsage(row), { includeDecodeRate: false })), ...(page.nextCursor ? { nextCursor: page.nextCursor } : {}), hasMore: page.hasMore, index: { @@ -184,7 +186,7 @@ export async function handleRequestHistoryRoutes(ctx: ManagementContext): Promis if (!entry) { return jsonResponse({ error: { code: "not_found", message: "unknown request" } }, 404, req, config); } - return jsonResponse(requestLogDto(requestLogEntryFromPersistedUsage(entry)), 200, req, config); + return jsonResponse(requestLogDto(requestLogEntryFromPersistedUsage(entry), { includeDecodeRate: false }), 200, req, config); } return null; diff --git a/src/server/management/shared.ts b/src/server/management/shared.ts index 7ed7c14b7e..214ca7a373 100644 --- a/src/server/management/shared.ts +++ b/src/server/management/shared.ts @@ -198,14 +198,26 @@ export function costResult(entry: MetricSource): CostResult { return { kind: "value", estimate, estimateReasons }; } -export function requestLogDto(entry: RequestLogEntry): Record { +/** + * `/api/logs` row projection. + * + * `includeDecodeRate` exists because `/api/request-history` shares this DTO but not its + * contract (#4038). The value would be meaningful there — `firstOutputMs` does survive into a + * persisted-usage row — so this is a scope decision, not a correctness one: the decode rate is + * a Logs-page metric, and widening a separate endpoint's response shape is not this change's + * business. Flipping it on later is one argument. + */ +export function requestLogDto( + entry: RequestLogEntry, + { includeDecodeRate = true }: { includeDecodeRate?: boolean } = {}, +): Record { return { ...entry, displayMetrics: { tokPerSecond: tokPerSecondResult(entry), // The parent uses the REQUEST's own TTFT. A combo parent must not borrow an attempt's, // which would measure a window the parent never had. - decodeTokPerSecond: decodeTokPerSecondResult(entry), + ...(includeDecodeRate ? { decodeTokPerSecond: decodeTokPerSecondResult(entry) } : {}), cost: costResult(entry), }, ...(entry.attempts?.length @@ -215,7 +227,7 @@ export function requestLogDto(entry: RequestLogEntry): Record { displayMetrics: { tokPerSecond: tokPerSecondResult(attempt), // Each attempt measures its own attempt-relative TTFT. - decodeTokPerSecond: decodeTokPerSecondResult(attempt), + ...(includeDecodeRate ? { decodeTokPerSecond: decodeTokPerSecondResult(attempt) } : {}), cost: costResult({ ...attempt, attempts: undefined, routeDecision: entry.routeDecision, requestedServiceTier: entry.requestedServiceTier, configuredServiceTier: entry.configuredServiceTier, responseServiceTier: entry.responseServiceTier }), }, })), diff --git a/tests/server/management-api-logs-metrics.test.ts b/tests/server/management-api-logs-metrics.test.ts index 3bdd37800a..27f9091557 100644 --- a/tests/server/management-api-logs-metrics.test.ts +++ b/tests/server/management-api-logs-metrics.test.ts @@ -597,4 +597,45 @@ describe("estimated decode rate (#4038)", () => { expect(dto!.attempts[0].displayMetrics.decodeTokPerSecond) .toEqual({ kind: "value", value: 30, estimated: true }); }); + + test("request history opts out of the decode rate, parent and attempts alike", async () => { + // /api/request-history shares this DTO but not its contract. The value would be meaningful + // there — firstOutputMs does survive into a persisted-usage row — so the exclusion is a + // scope decision rather than a correctness one, and it has to be asserted or it silently + // reverses the first time someone touches the DTO. + const { requestLogDto } = await import("../../src/server/management/shared"); + const entry = baseEntry({ + durationMs: 10_000, + firstOutputMs: 2_000, + usage: { inputTokens: 10, outputTokens: 240 }, + attempts: [{ + provider: "anthropic", + model: "claude-3-haiku-20240307", + durationMs: 10_000, + firstOutputMs: 2_000, + usageStatus: "reported", + usage: { inputTokens: 10, outputTokens: 240 }, + }], + } as Partial); + + const history = requestLogDto(entry, { includeDecodeRate: false }) as Record; + expect(Object.hasOwn(history.displayMetrics, "decodeTokPerSecond")).toBe(false); + expect(Object.hasOwn(history.attempts[0].displayMetrics, "decodeTokPerSecond")).toBe(false); + // Everything else the endpoint already returned is untouched. + expect(history.displayMetrics.tokPerSecond.kind).toBe("value"); + expect(history.displayMetrics.cost).toBeDefined(); + + // The default is still to include it, so /api/logs is unaffected by the opt-out existing. + const logs = requestLogDto(entry) as Record; + expect(logs.displayMetrics.decodeTokPerSecond).toEqual({ kind: "value", value: 30, estimated: true }); + }); + + test("the request-history route actually passes the opt-out", async () => { + // The DTO assertion above proves the flag works; this proves the endpoint uses it. Without + // it, a correct flag and a route that never sets it would both look fine. + const source = await Bun.file("src/server/management/request-history-routes.ts").text(); + const calls = [...source.matchAll(/requestLogDto\(/g)]; + expect(calls.length).toBeGreaterThan(0); + expect([...source.matchAll(/includeDecodeRate: false/g)]).toHaveLength(calls.length); + }); }); From d5e042c9c52ebb460bcf9ae6eabce842c9a8246a Mon Sep 17 00:00:00 2001 From: JUN Date: Thu, 10 Sep 2026 09:44:13 +0900 Subject: [PATCH 3/3] fix(logs): stop passing requestLogDto point-free to Array.map Typecheck failure at b19fa9e35. /api/logs built its rows with .map(requestLogDto), which is fine for a one-parameter function and a type error the moment a second one exists: Array.map passes (value, index, array), so the element INDEX was being handed to the new options object. Type 'number' has no properties in common with type '{ includeDecodeRate?: boolean }' An explicit arrow fixes it and keeps the default, which is what /api/logs wants. The two request-history call sites were already explicit because they pass the opt-out. This is the whole cost of the flag -- one call site that happened to be point-free -- so the exclusion stays rather than being traded for a documented deviation. --- src/server/management/logs-usage-routes.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/server/management/logs-usage-routes.ts b/src/server/management/logs-usage-routes.ts index a66ff4b79c..72a019d0a2 100644 --- a/src/server/management/logs-usage-routes.ts +++ b/src/server/management/logs-usage-routes.ts @@ -115,7 +115,10 @@ export async function handleLogsUsageRoutes(ctx: ManagementContext): Promise requestLogDto(entry)); const poll = selectRequestLogPoll(logs, url.searchParams, cursor); return jsonResponse({ timeZone: Intl.DateTimeFormat().resolvedOptions().timeZone,