Skip to content

Commit cf24015

Browse files
myk1ytmyk1yt
committed
fix(usage): log a bounded descriptor instead of the raw malformed value
What: stop passing the raw provider value to the diagnostics sink. The warning now carries the value's type, plus a size-safe payload: the numeric value for numbers, and `length` plus a 64-character preview for strings. Everything else keeps only its type. Why: CodeRabbit thread r4426662673. `CompactTransport.write` serializes the meta object and writes it synchronously to stdout and to ./logs/app.log, so a large provider value would block the event loop and grow the log file. The value arrives straight off the wire and is unbounded, so it must not be logged verbatim. Impact: diagnostics stay useful (which field, what type, how big, and a short preview) while the emitted payload is bounded. A 1MB string now produces a 241-byte log line. Dedupe semantics are unchanged: one warning per alias per process. Tests: the four existing diagnostic cases now assert the descriptor shape rather than the raw value, and seven cases were added: one with a 1MB string asserting the payload stays bounded, and six covering the per-type descriptors. All ten fail on the previous head 41d6ab0. Refs: #2254 (comment)
1 parent 41d6ab0 commit cf24015

2 files changed

Lines changed: 98 additions & 5 deletions

File tree

‎src/api/transform/__tests__/chat-usage-normalization.spec.ts‎

Lines changed: 60 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -189,7 +189,9 @@ describe("normalizeChatUsage", () => {
189189

190190
expect(warn).toHaveBeenCalledWith(expect.any(String), {
191191
path: "prompt_cache_miss_tokens",
192-
value: "30",
192+
type: "string",
193+
length: 2,
194+
preview: "30",
193195
})
194196
} finally {
195197
warn.mockRestore()
@@ -214,7 +216,9 @@ describe("normalizeChatUsage", () => {
214216

215217
expect(warn).toHaveBeenCalledWith(expect.stringContaining("malformed token counter"), {
216218
path: "prompt_cache_miss_tokens",
217-
value: "30",
219+
type: "string",
220+
length: 2,
221+
preview: "30",
218222
})
219223
} finally {
220224
warn.mockRestore()
@@ -273,17 +277,69 @@ describe("normalizeChatUsage", () => {
273277

274278
expect(warn).toHaveBeenCalledWith(expect.stringContaining("malformed token counter"), {
275279
path: "prompt_tokens",
276-
value: "100",
280+
type: "string",
281+
length: 3,
282+
preview: "100",
277283
})
278284
expect(warn).toHaveBeenCalledWith(expect.stringContaining("malformed token counter"), {
279285
path: "completion_tokens",
280-
value: -1,
286+
type: "number",
287+
preview: -1,
281288
})
282289
} finally {
283290
warn.mockRestore()
284291
}
285292
})
286293

294+
it("keeps the logged payload bounded for an arbitrarily large provider value", async () => {
295+
vi.resetModules()
296+
const { CompactLogger: FreshCompactLogger } = await import("../../../utils/logging/CompactLogger")
297+
const { normalizeChatUsage: freshNormalize } = await import("../chat-usage-normalization")
298+
const warn = vi.spyOn(FreshCompactLogger.prototype, "warn").mockImplementation(() => {})
299+
const huge = "9".repeat(1_000_000)
300+
301+
try {
302+
freshNormalize({ prompt_tokens: 120, prompt_cache_miss_tokens: huge })
303+
304+
const [, meta] = warn.mock.calls[0] as [string, Record<string, unknown>]
305+
306+
// The raw megabyte must not reach the transport, which stringifies
307+
// and writes it synchronously to stdout and the log file.
308+
expect(meta).not.toHaveProperty("value")
309+
expect(meta.type).toBe("string")
310+
expect(meta.length).toBe(1_000_000)
311+
expect(typeof meta.preview).toBe("string")
312+
expect((meta.preview as string).length).toBeLessThanOrEqual(65)
313+
expect(JSON.stringify(meta).length).toBeLessThan(200)
314+
} finally {
315+
warn.mockRestore()
316+
}
317+
})
318+
319+
it.each([
320+
["a boolean", true, { type: "boolean" }],
321+
["an object", { tokens: 30 }, { type: "object" }],
322+
["an array", [1, 2, 3], { type: "array" }],
323+
["NaN", NaN, { type: "number", preview: NaN }],
324+
["Infinity", Infinity, { type: "number", preview: Infinity }],
325+
["a fractional number", 1.5, { type: "number", preview: 1.5 }],
326+
])("describes %s without logging the raw value", async (_name, malformed, expected) => {
327+
vi.resetModules()
328+
const { CompactLogger: FreshCompactLogger } = await import("../../../utils/logging/CompactLogger")
329+
const { normalizeChatUsage: freshNormalize } = await import("../chat-usage-normalization")
330+
const warn = vi.spyOn(FreshCompactLogger.prototype, "warn").mockImplementation(() => {})
331+
332+
try {
333+
freshNormalize({ prompt_tokens: 120, prompt_cache_miss_tokens: malformed })
334+
335+
const [, meta] = warn.mock.calls[0] as [string, Record<string, unknown>]
336+
337+
expect(meta).toEqual({ path: "prompt_cache_miss_tokens", ...expected })
338+
} finally {
339+
warn.mockRestore()
340+
}
341+
})
342+
287343
it("stays silent for counters the provider simply did not report", () => {
288344
const warn = vi.spyOn(CompactLogger.prototype, "warn").mockImplementation(() => {})
289345

‎src/api/transform/chat-usage-normalization.ts‎

Lines changed: 38 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -117,9 +117,46 @@ const isTokenCount = (value: unknown): value is number =>
117117
*/
118118
const usageLogger = new CompactLogger()
119119

120+
/**
121+
* Longest string preview kept in a diagnostic. A provider can send an
122+
* arbitrarily large value, and the transport stringifies it and writes it
123+
* synchronously to stdout and to the log file, so the payload is capped.
124+
*/
125+
const MAX_PREVIEW_CHARS = 64
126+
127+
/**
128+
* Size-safe description of a discarded counter value.
129+
*
130+
* The raw value is never logged: it comes off the wire and is unbounded, while
131+
* `CompactTransport.write` serializes and writes it synchronously. A number is
132+
* at most a couple of dozen characters when stringified, so its value is both
133+
* safe and the most diagnosable thing to keep. A string keeps its length plus a
134+
* capped preview. Everything else keeps only its type.
135+
*/
136+
const describeMalformedCount = (value: unknown): { type: string; preview?: string | number; length?: number } => {
137+
if (typeof value === "number") {
138+
return { type: "number", preview: value }
139+
}
140+
141+
if (typeof value === "string") {
142+
return {
143+
type: "string",
144+
length: value.length,
145+
preview: value.length > MAX_PREVIEW_CHARS ? `${value.slice(0, MAX_PREVIEW_CHARS)}…` : value,
146+
}
147+
}
148+
149+
if (Array.isArray(value)) return { type: "array" }
150+
151+
return { type: value === null ? "null" : typeof value }
152+
}
153+
120154
const emitMalformedCountWarning = (path: string, value: unknown): void => {
121155
try {
122-
usageLogger.warn("Discarded a malformed token counter while normalizing chat usage", { path, value })
156+
usageLogger.warn("Discarded a malformed token counter while normalizing chat usage", {
157+
path,
158+
...describeMalformedCount(value),
159+
})
123160
} catch {
124161
// Diagnostics are best-effort; never let a sink failure escape into usage accounting.
125162
}

0 commit comments

Comments
 (0)