mirror of
https://github.com/diegosouzapw/OmniRoute.git
synced 2026-08-15 11:43:10 +03:00
feat(logging): make the chat-log truncation limit configurable, bumped default 128x
The 8KB cap on logged request/response bodies (open-sse/handlers/chatCore/logTruncation.ts::truncateForLog()) was hardcoded — trivially exceeded by any real multi-turn agentic conversation, meaning the dashboard's "Full Conversation" panel could only ever show a placeholder instead of the actual messages for nearly every logged row of any conversation with real substance. - Added CHAT_LOG_MAX_BODY_KB env var (src/lib/logEnv.ts:: getChatLogMaxBodyBytes()), default 1024 KB (1MB) — a 128x bump from the old hardcoded 8KB — following the same configurable-limit pattern as the sibling CHAT_LOG_TEXT_LIMIT/CHAT_LOG_ARRAY_TAIL_ITEMS/etc. vars. - Documented in .env.example and docs/reference/ENVIRONMENT.md. estimateSizeFast() (open-sse/utils/estimateSize.ts) has been substantially rewritten upstream since this bug was first found (now an iterative Frame-based walker with a separate node-visit budget, not the simple stack loop originally patched) — re-implemented the fix against the current algorithm rather than porting the old diff: the byte early-exit was unconditionally the module-level ESTIMATE_SIZE_BYTE_LIMIT (256 KiB) with no way for a caller to raise it, so any caller comparing against a bigger configured threshold could never see a size above ~256 KiB — every payload between 256 KiB and the caller's real limit looked "under threshold" and truncation never fired, the opposite of intended. Added an optional byteLimit parameter (default unchanged at ESTIMATE_SIZE_BYTE_LIMIT, so isSmallEnoughForSemanticCache's existing behavior is untouched) threaded through both the byte-check early-exit and the node-budget-exhaustion fail-closed fallback, with truncateForLog() now passing its own configured getChatLogMaxBodyBytes() value through.
This commit is contained in:
committed by
diegosouzapw
parent
aae408f585
commit
620917fbc0
@@ -1429,6 +1429,7 @@ APP_LOG_TO_FILE=true
|
||||
# CHAT_LOG_ARRAY_TAIL_ITEMS=24 # Number of array items retained from tail (default: 24)
|
||||
# CHAT_LOG_MAX_DEPTH=6 # Max nesting depth before truncation (default: 6)
|
||||
# CHAT_LOG_MAX_OBJECT_KEYS=80 # Max object keys retained (default: 80, 0 = no limit)
|
||||
# CHAT_LOG_MAX_BODY_KB=1024 # Max request/response body size before summarizing, in KB (default: 1024)
|
||||
|
||||
# Maximum rows in the proxy_logs SQLite table.
|
||||
# Default: 100000
|
||||
|
||||
@@ -744,6 +744,7 @@ The logging system writes to both stdout and rotated log files. All configuratio
|
||||
| `CHAT_LOG_ARRAY_TAIL_ITEMS` | `24` | Number of array items retained from the tail when truncating chat log payloads. |
|
||||
| `CHAT_LOG_MAX_DEPTH` | `6` | Max nesting depth before chat log payloads are truncated. |
|
||||
| `CHAT_LOG_MAX_OBJECT_KEYS` | `80` | Max object keys retained in chat log payloads (0 = unlimited). |
|
||||
| `CHAT_LOG_MAX_BODY_KB` | `1024` | Max request/response body size before `truncateForLog()` summarizes it, in KB. |
|
||||
| `CHAT_DEBUG_FILE` | `false` | When true, `serializeArtifactForStorage` skips size-based truncation. Debug only. |
|
||||
|
||||
---
|
||||
|
||||
@@ -3,11 +3,11 @@ import {
|
||||
getChatLogMaxDepth,
|
||||
getChatLogArrayTailItems,
|
||||
getChatLogMaxObjectKeys,
|
||||
getChatLogMaxBodyBytes,
|
||||
} from "@/lib/logEnv";
|
||||
import { estimateSizeFast } from "../../utils/estimateSize.ts";
|
||||
|
||||
export const MEMORY_EXTRACTION_TEXT_LIMIT = 64 * 1024;
|
||||
const MAX_LOG_BODY_CHARS = 8 * 1024; // 8KB cap for logged request/response bodies
|
||||
|
||||
export function capMemoryExtractionText(value: string): string {
|
||||
if (value.length <= MEMORY_EXTRACTION_TEXT_LIMIT) return value;
|
||||
@@ -60,9 +60,10 @@ export function cloneBoundedChatLogPayload(value: unknown, depth = 0): unknown {
|
||||
|
||||
/**
|
||||
* Truncate a large object for logging. If its JSON representation exceeds
|
||||
* MAX_LOG_BODY_CHARS, return a lightweight summary instead of the full clone.
|
||||
* This prevents persistAttemptLogs from holding multi-MB references to
|
||||
* translatedBody across 17 call sites per request.
|
||||
* the configured max body size (getChatLogMaxBodyBytes()), return a
|
||||
* lightweight summary instead of the full clone. This prevents
|
||||
* persistAttemptLogs from holding multi-MB references to translatedBody
|
||||
* across 17 call sites per request.
|
||||
*
|
||||
* When the summarized object carries a `tools` definition, re-attach it
|
||||
* (bounded via `cloneBoundedChatLogPayload`) so the request-details view can
|
||||
@@ -75,8 +76,9 @@ export function cloneBoundedChatLogPayload(value: unknown, depth = 0): unknown {
|
||||
export function truncateForLog(value: unknown): Record<string, unknown> | null | undefined {
|
||||
if (value === null || value === undefined) return value as null | undefined;
|
||||
if (typeof value !== "object") return value as unknown as Record<string, unknown>;
|
||||
const estimatedSize = estimateSizeFast(value);
|
||||
if (estimatedSize <= MAX_LOG_BODY_CHARS) return value as Record<string, unknown>;
|
||||
const maxBodyBytes = getChatLogMaxBodyBytes();
|
||||
const estimatedSize = estimateSizeFast(value, maxBodyBytes);
|
||||
if (estimatedSize <= maxBodyBytes) return value as Record<string, unknown>;
|
||||
// Object is too large — return a summary instead of a deep clone
|
||||
const obj = value as Record<string, unknown>;
|
||||
const summary: Record<string, unknown> = {
|
||||
|
||||
@@ -3,15 +3,20 @@
|
||||
* Safe for circular references (WeakSet). Iterative frames only (no recursive call stack).
|
||||
*
|
||||
* Budgets:
|
||||
* - ESTIMATE_SIZE_BYTE_LIMIT (256 KiB): early-exit once counted bytes exceed the limit
|
||||
* - byteLimit param (default ESTIMATE_SIZE_BYTE_LIMIT, 256 KiB): early-exit
|
||||
* once counted bytes exceed the limit — pass the caller's own threshold
|
||||
* explicitly rather than relying on the default, since a caller comparing
|
||||
* against a bigger configured limit would otherwise never see a size
|
||||
* above 256 KiB.
|
||||
* - ESTIMATE_SIZE_NODE_BUDGET: max value visits (containers + primitives/elements)
|
||||
*
|
||||
* Arrays are walked by index frame (never pre-push/copy every element reference).
|
||||
* Plain objects yield own enumerable values incrementally (no Object.keys materialization).
|
||||
* Node-budget exhaustion returns a value strictly above 256 KiB so callers fail closed.
|
||||
* Node-budget exhaustion returns a value strictly above the effective byteLimit
|
||||
* so callers fail closed.
|
||||
*/
|
||||
|
||||
/** Byte early-exit threshold (256 KiB). */
|
||||
/** Default byte early-exit threshold (256 KiB) when a caller doesn't pass its own. */
|
||||
export const ESTIMATE_SIZE_BYTE_LIMIT = 262_144;
|
||||
|
||||
/**
|
||||
@@ -74,14 +79,22 @@ function expandContainerFrame(stack: Frame[], frame: Exclude<Frame, ValueFrame>)
|
||||
stack.push({ t: "v", v: (frame.o as Record<string, unknown>)[next.value] });
|
||||
}
|
||||
|
||||
export function estimateSizeFast(value: unknown): number {
|
||||
/**
|
||||
* @param byteLimit - early-exit threshold (default ESTIMATE_SIZE_BYTE_LIMIT,
|
||||
* 256 KiB). Pass the actual threshold you're comparing against (see
|
||||
* chatCore/logTruncation.ts::truncateForLog) so raising that threshold
|
||||
* doesn't silently cap what this function is even capable of reporting —
|
||||
* the byte check and the node-budget fail-closed fallback both key off this
|
||||
* value, not the fixed module constant, when a caller supplies one.
|
||||
*/
|
||||
export function estimateSizeFast(value: unknown, byteLimit = ESTIMATE_SIZE_BYTE_LIMIT): number {
|
||||
let bytes = 0;
|
||||
let visitsLeft = ESTIMATE_SIZE_NODE_BUDGET;
|
||||
const seen = new WeakSet<object>();
|
||||
const stack: Frame[] = [{ t: "v", v: value }];
|
||||
|
||||
while (stack.length > 0) {
|
||||
if (visitsLeft <= 0) return ESTIMATE_SIZE_BYTE_LIMIT + 1;
|
||||
if (visitsLeft <= 0) return byteLimit + 1;
|
||||
|
||||
const frame = stack.pop()!;
|
||||
if (!isValueFrame(frame)) {
|
||||
@@ -96,7 +109,7 @@ export function estimateSizeFast(value: unknown): number {
|
||||
const ty = typeof v;
|
||||
if (ty === "string" || ty === "number" || ty === "boolean") {
|
||||
bytes = addPrimitiveBytes(bytes, v as string | number | boolean);
|
||||
if (bytes > ESTIMATE_SIZE_BYTE_LIMIT) return bytes;
|
||||
if (bytes > byteLimit) return bytes;
|
||||
continue;
|
||||
}
|
||||
if (ty === "object") {
|
||||
|
||||
@@ -158,6 +158,16 @@ export function getChatLogMaxObjectKeys(): number {
|
||||
return parseNonNegativeInt(process.env.CHAT_LOG_MAX_OBJECT_KEYS, 80);
|
||||
}
|
||||
|
||||
/**
|
||||
* Was a hardcoded/default 8KB — trivially exceeded by any real multi-turn
|
||||
* agentic conversation, meaning the dashboard's "Full Conversation" panel
|
||||
* could only ever show a placeholder instead of the actual messages for
|
||||
* nearly every logged row of any conversation with real substance.
|
||||
*/
|
||||
export function getChatLogMaxBodyBytes(): number {
|
||||
return parsePositiveInt(process.env.CHAT_LOG_MAX_BODY_KB, 1024) * 1024;
|
||||
}
|
||||
|
||||
export function isChatDebugFileEnabled(): boolean {
|
||||
if (parseBoolean(process.env.CHAT_DEBUG_FILE, false)) return true;
|
||||
return process.env.APP_LOG_LEVEL?.trim().toLowerCase() === "debug";
|
||||
|
||||
@@ -242,3 +242,35 @@ test("truncateForLog leaves small requests with `tools` unchanged (no regression
|
||||
// untouched — same reference, not a summary or a clone
|
||||
assert.equal(result, small);
|
||||
});
|
||||
|
||||
/**
|
||||
* Real bug: the 8KB cap on logged request/response bodies was hardcoded,
|
||||
* trivially exceeded by any real multi-turn agentic conversation — the
|
||||
* dashboard's "Full Conversation" panel could only ever show a placeholder
|
||||
* instead of the actual messages for nearly every logged row of any
|
||||
* conversation with real substance. CHAT_LOG_MAX_BODY_KB makes this
|
||||
* configurable; this pins that truncateForLog() actually reads it (not a
|
||||
* baked-in literal) by proving a payload just over the OLD 8KB default
|
||||
* survives untouched under a raised limit, then gets summarized again once
|
||||
* the limit is lowered below it.
|
||||
*/
|
||||
test("truncateForLog honors a configured CHAT_LOG_MAX_BODY_KB instead of a hardcoded cap", () => {
|
||||
const saved = process.env.CHAT_LOG_MAX_BODY_KB;
|
||||
const payload = {
|
||||
model: "gpt-4o",
|
||||
// ~12KB of content — comfortably over the old hardcoded 8KB cap.
|
||||
messages: [{ role: "user", content: "x".repeat(12 * 1024) }],
|
||||
};
|
||||
try {
|
||||
process.env.CHAT_LOG_MAX_BODY_KB = "1"; // 1KB — payload must be summarized
|
||||
const summarized = truncateForLog(payload) as Record<string, unknown>;
|
||||
assert.equal(summarized._truncated, true, "expected summarization under a 1KB limit");
|
||||
|
||||
process.env.CHAT_LOG_MAX_BODY_KB = "64"; // 64KB — payload must pass through untouched
|
||||
const untouched = truncateForLog(payload);
|
||||
assert.equal(untouched, payload, "expected the payload untouched under a 64KB limit");
|
||||
} finally {
|
||||
if (saved === undefined) delete process.env.CHAT_LOG_MAX_BODY_KB;
|
||||
else process.env.CHAT_LOG_MAX_BODY_KB = saved;
|
||||
}
|
||||
});
|
||||
|
||||
@@ -68,6 +68,55 @@ test("estimateSizeFast early-exits at 262144 bytes (256KB)", () => {
|
||||
assert.ok(result >= 262144, `Should early-exit, got ${result}`);
|
||||
});
|
||||
|
||||
/**
|
||||
* Real bug: the byte early-exit was unconditionally ESTIMATE_SIZE_BYTE_LIMIT
|
||||
* (256 KiB) with no way for a caller to raise it, so any caller comparing
|
||||
* against a bigger configured threshold (e.g. logTruncation.ts's
|
||||
* getChatLogMaxBodyBytes(), default 1 MiB) could never see a size above
|
||||
* ~256 KiB — every payload up to their real threshold looked "under
|
||||
* threshold" and truncation never fired for anything between 256 KiB and
|
||||
* the caller's actual limit, silently letting oversized bodies through.
|
||||
*/
|
||||
test("estimateSizeFast respects a caller-supplied byteLimit above the 256KB default", () => {
|
||||
const oneMiB = 1024 * 1024;
|
||||
// Multiple 200KB elements: the 2nd element alone already crosses the
|
||||
// default 256KB limit, so a hardcoded-256KB implementation early-exits
|
||||
// there and never accumulates the 3rd/4th elements — only a truly
|
||||
// caller-configurable limit reports the full, accurate total.
|
||||
const payload = Array.from({ length: 4 }, () => "x".repeat(200_000));
|
||||
const trueTotal = payload.reduce((sum, s) => sum + s.length, 0);
|
||||
|
||||
const withDefaultLimit = estimateSizeFast(payload);
|
||||
assert.ok(
|
||||
withDefaultLimit < trueTotal,
|
||||
`sanity: default 256KB limit must early-exit before the true total, got ${withDefaultLimit}`
|
||||
);
|
||||
|
||||
const withCustomLimit = estimateSizeFast(payload, oneMiB);
|
||||
assert.equal(
|
||||
withCustomLimit,
|
||||
trueTotal,
|
||||
"must report the true accumulated size instead of early-exiting at the default 256KB"
|
||||
);
|
||||
assert.ok(withCustomLimit <= oneMiB, "payload must be recognized as under the caller's own limit");
|
||||
});
|
||||
|
||||
test("estimateSizeFast node-budget fail-closed return respects a caller-supplied byteLimit", () => {
|
||||
const oneMiB = 1024 * 1024;
|
||||
const hugeSparseArray = new Proxy([] as unknown[], {
|
||||
get(target, prop, receiver) {
|
||||
if (prop === "length") return 5_000_000;
|
||||
if (typeof prop === "string" && /^[0-9]+$/.test(prop)) return null;
|
||||
return Reflect.get(target, prop, receiver);
|
||||
},
|
||||
});
|
||||
const result = estimateSizeFast(hugeSparseArray, oneMiB);
|
||||
assert.ok(
|
||||
result > oneMiB,
|
||||
`node-budget exhaustion must fail closed above the CALLER's limit (${oneMiB}), not the default 256KB — got ${result}`
|
||||
);
|
||||
});
|
||||
|
||||
test("estimateSizeFast checks byte limit after numbers and booleans", () => {
|
||||
const almostForNumber = "x".repeat(ESTIMATE_SIZE_BYTE_LIMIT - 4);
|
||||
const withNumber = estimateSizeFast([almostForNumber, 1]);
|
||||
|
||||
Reference in New Issue
Block a user