mirror of
https://github.com/diegosouzapw/OmniRoute.git
synced 2026-08-12 18:22:48 +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 (both
required — tests/unit/issue-7793-env-doc-sync-repro.test.ts and
check-env-doc-sync.test.ts enforce this pairing).
Found and fixed a real bug while wiring this up: estimateSize.ts's
estimateSizeFast() had its own hardcoded 256KB early-exit optimization
("stop walking once bytes clearly exceeds the caller's threshold"), so it
could never report a size above ~256KB regardless of the object's true
size — meaning any caller threshold configured above 256KB (like the new
1MB default) was silently unreachable; every payload would look "under
threshold" and truncation would never fire, letting arbitrarily large
bodies through unbounded (the opposite of intended, and a real memory-
protection regression). Fixed by giving estimateSizeFast() a parameterized
earlyExitAt (default unchanged at 262144, so isSmallEnoughForSemanticCache's
existing behavior is untouched), with truncateForLog() now passing its own
configured getChatLogMaxBodyBytes() value through.
Also adds a "Conversation" field to the request detail panel's metadata
grid (last, after "Combo"), showing the request's conversation id
(sessionTag) for quick reference/copy.
Test plan:
- New TDD tests for both fixes (Responses API messageCount capture — from
the previous commit — and the estimateSizeFast earlyExitAt parameter),
confirmed failing before each fix and passing after
- Bumped the two truncateForLog test fixtures that were sized against the
old 8KB threshold so they still genuinely exceed the new ~1MB default
- npm run typecheck:core / npm run lint / npm run check:file-size — clean
- npm run test:unit — 27132 tests, same 4 pre-existing/unrelated failures
as the last confirmed-clean run (no new regressions) — including the two
env/doc-sync contract tests that initially caught the missing
CHAT_LOG_MAX_BODY_KB documentation, now fixed
- npm run test:vitest — 291/291 passed
- Rebuilt and redeployed to omniroute-dev
This commit is contained in:
Markus Hartung
@@ -1360,6 +1360,11 @@ 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 # Whole request/response body size before it's replaced by a bare
|
||||
# {_truncated, messageCount, ...} summary instead of the full clone
|
||||
# (default: 1024 KB / 1MB). Raise this if the dashboard's "Full
|
||||
# Conversation" transcript panel shows a placeholder instead of the
|
||||
# actual messages for long agentic conversations.
|
||||
|
||||
# Maximum rows in the proxy_logs SQLite table.
|
||||
# Default: 100000
|
||||
|
||||
@@ -158,7 +158,7 @@
|
||||
"_rebaseline_2026_06_20_4389_thinking_toolchoice": "Re-baseline base.ts 1387->1399 (#4389): tool_choice-forced thinking guard at the existing Claude wire-image injection chokepoint (effThinking gate avoids the Anthropic 400 when tool_choice forces a tool). Cohesive guard; structural shrink tracked in #3501.",
|
||||
"_rebaseline_2026_07_18_6979_codex_test": "PR #6979 own growth: executor-codex.test.ts 1340->1347 (+7 = generalized ensureThinkingBudget assertion added to the existing codex thinking-budget cases). antigravity-test bump 942->977 REVERTED here: #7408's test split dropped that file to 888, so this PR's +35 fits under the original 942 frozen cap.",
|
||||
"_rebaseline_2026_07_24_8354_logs_timeline_sidebar": "PR #8354 (hartmark, feature/scrolling-log) own growth: src/shared/constants/sidebarVisibility/sections.ts 812->820 (+8, the single new logs-timeline SidebarItemDefinition entry added to LOGS_GROUP.items for the new /dashboard/logs/timeline scrolling request-timeline page). Irreducible data-literal wiring at the existing sidebar-sections chokepoint, same shape as every other item in the file; not extractable without an ad-hoc single-item exception to the file's otherwise-uniform multi-line item style.",
|
||||
"_rebaseline_2026_08_04_9439_agentic_conversation_tracking": "PR #9439 (hartmark, feat/agentic-conversation-tracking) own growth: adds agentic multi-turn conversation tracking (X-ConversationId, fingerprint+prefix-hash continuation detection) plus a full dashboard surface for it. src/sse/handlers/chat.ts 1845->1868 (+23, conversationId resolution + X-ConversationId header wiring at the existing chat-request chokepoint, threaded to executeChatWithBreaker). open-sse/handlers/chatCore.ts 5020->5024 (+4, sessionTag passthrough on the trackPendingRequest() call so an in-flight/streaming request's conversation transcript can be reconstructed live — see #9315 fix in the same PR). src/shared/components/RequestLoggerV2.tsx 1629->1643 (+14, onNavigateToLog wiring so a turn/next-message click in the new conversation panel can open another request's detail without leaving the logs list). Two files cross the 1000-line new-file cap because they gained the actual UI feature body, not incidental wiring: src/shared/components/RequestLoggerDetail.tsx (new cap, 1241) gained the 'Full Conversation' transcript section (Markdown rendering, per-turn timestamps, turn-relative view, click-to-navigate, live auto-refresh/auto-follow fed from the in-flight SSE buffer, mobile-responsive header) and src/shared/components/RequestTimeline.tsx (new cap, 1037) gained conversation-aware lane grouping/connector-arrow rendering, mobile responsiveness, and configurable poll-interval controls; both are the dashboard-side half of this PR's actual feature, not extractable without splitting an existing single-modal/single-canvas component mid-feature. open-sse/executors/base.ts 1578->1623 (+45) is NOT this PR's change — confirmed via `git diff upstream/release/v3.8.50 HEAD -- open-sse/executors/base.ts` (empty) — it is release/v3.8.50's own pre-existing drift past its frozen cap, inherited via this branch's rebase onto the current release tip; rebaselined here only because check:file-size runs against the full merged tree and this PR's rebase is what surfaced it. Covered by tests/unit/conversationTracker.test.ts, agenticConversations.test.ts, multiRowConversation.test.ts, request-timeline-lane-allocation.test.ts, stream-payload-collector.test.ts. Structural shrink of RequestLoggerDetail.tsx/RequestTimeline.tsx tracked in #3501.",
|
||||
"_rebaseline_2026_08_04_9439_agentic_conversation_tracking": "PR #9439 (hartmark, feat/agentic-conversation-tracking) own growth: adds agentic multi-turn conversation tracking (X-ConversationId, fingerprint+prefix-hash continuation detection) plus a full dashboard surface for it. src/sse/handlers/chat.ts 1845->1868 (+23, conversationId resolution + X-ConversationId header wiring at the existing chat-request chokepoint, threaded to executeChatWithBreaker). open-sse/handlers/chatCore.ts 5020->5024 (+4, sessionTag passthrough on the trackPendingRequest() call so an in-flight/streaming request's conversation transcript can be reconstructed live — see #9315 fix in the same PR). src/shared/components/RequestLoggerV2.tsx 1629->1643 (+14, onNavigateToLog wiring so a turn/next-message click in the new conversation panel can open another request's detail without leaving the logs list). Two files cross the 1000-line new-file cap because they gained the actual UI feature body, not incidental wiring: src/shared/components/RequestLoggerDetail.tsx (new cap, 1241->1256 after a follow-up +15: a 'Conversation' field added to the metadata grid, last after 'Combo', showing the request's sessionTag/conversation id) gained the 'Full Conversation' transcript section (Markdown rendering, per-turn timestamps, turn-relative view, click-to-navigate, live auto-refresh/auto-follow fed from the in-flight SSE buffer, mobile-responsive header) and src/shared/components/RequestTimeline.tsx (new cap, 1037) gained conversation-aware lane grouping/connector-arrow rendering, mobile responsiveness, and configurable poll-interval controls; both are the dashboard-side half of this PR's actual feature, not extractable without splitting an existing single-modal/single-canvas component mid-feature. open-sse/executors/base.ts 1578->1623 (+45) is NOT this PR's change — confirmed via `git diff upstream/release/v3.8.50 HEAD -- open-sse/executors/base.ts` (empty) — it is release/v3.8.50's own pre-existing drift past its frozen cap, inherited via this branch's rebase onto the current release tip; rebaselined here only because check:file-size runs against the full merged tree and this PR's rebase is what surfaced it. Covered by tests/unit/conversationTracker.test.ts, agenticConversations.test.ts, multiRowConversation.test.ts, request-timeline-lane-allocation.test.ts, stream-payload-collector.test.ts. Structural shrink of RequestLoggerDetail.tsx/RequestTimeline.tsx tracked in #3501.",
|
||||
"cap": 1000,
|
||||
"testCap": 1000,
|
||||
"testFrozen": {
|
||||
@@ -404,7 +404,7 @@
|
||||
"src/shared/components/analytics/charts.tsx": 1035,
|
||||
"src/shared/services/cliRuntime.ts": 1122,
|
||||
"src/sse/handlers/chat.ts": 1868,
|
||||
"src/shared/components/RequestLoggerDetail.tsx": 1241,
|
||||
"src/shared/components/RequestLoggerDetail.tsx": 1256,
|
||||
"src/shared/components/RequestTimeline.tsx": 1037,
|
||||
"src/sse/services/auth.ts": 2508,
|
||||
"tests/unit/account-fallback-service.test.ts": 1572,
|
||||
|
||||
@@ -723,6 +723,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` | Whole request/response body size (KB) before it's replaced by a bare summary instead of the full clone. Raise this if long agentic conversations show a placeholder instead of the real messages in the dashboard. |
|
||||
| `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.
|
||||
* getChatLogMaxBodyBytes() (default 1MB; CHAT_LOG_MAX_BODY_KB env override),
|
||||
* return a lightweight summary instead of the full clone. This prevents
|
||||
* persistAttemptLogs from holding unbounded 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,12 @@ 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 maxBytes = getChatLogMaxBodyBytes();
|
||||
// Pass maxBytes as the early-exit point — otherwise estimateSizeFast's own
|
||||
// default 256KB early-exit caps what it can ever report, silently making
|
||||
// any configured threshold above 256KB unreachable (#trunc-limit-config).
|
||||
const estimatedSize = estimateSizeFast(value, maxBytes);
|
||||
if (estimatedSize <= maxBytes) 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> = {
|
||||
|
||||
@@ -1,9 +1,14 @@
|
||||
/**
|
||||
* Fast object-tree size estimator — walks without JSON.stringify.
|
||||
* Safe for circular references (uses WeakSet).
|
||||
* Early-exits at 256KB to avoid wasting CPU on huge payloads.
|
||||
* Early-exits once `bytes` crosses `earlyExitAt` (default 256KB) to avoid
|
||||
* wasting CPU on huge payloads — the caller only needs "is this over my
|
||||
* threshold", not an exact total for values that are already way over it.
|
||||
* 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.
|
||||
*/
|
||||
export function estimateSizeFast(value: unknown): number {
|
||||
export function estimateSizeFast(value: unknown, earlyExitAt = 262144): number {
|
||||
let bytes = 0;
|
||||
const stack: unknown[] = [value];
|
||||
const seen = new WeakSet();
|
||||
@@ -12,7 +17,7 @@ export function estimateSizeFast(value: unknown): number {
|
||||
if (v === null || v === undefined) continue;
|
||||
if (typeof v === "string") {
|
||||
bytes += v.length;
|
||||
if (bytes > 262144) return bytes;
|
||||
if (bytes > earlyExitAt) return bytes;
|
||||
} else if (typeof v === "number") bytes += 8;
|
||||
else if (typeof v === "boolean") bytes += 4;
|
||||
else if (typeof v === "object") {
|
||||
@@ -22,7 +27,8 @@ export function estimateSizeFast(value: unknown): number {
|
||||
for (let i = 0; i < v.length; i++) stack.push(v[i]);
|
||||
} else {
|
||||
for (const key in v) {
|
||||
if (Object.prototype.hasOwnProperty.call(v, key)) stack.push((v as Record<string, unknown>)[key]);
|
||||
if (Object.prototype.hasOwnProperty.call(v, key))
|
||||
stack.push((v as Record<string, unknown>)[key]);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -158,6 +158,23 @@ export function getChatLogMaxObjectKeys(): number {
|
||||
return parseNonNegativeInt(process.env.CHAT_LOG_MAX_OBJECT_KEYS, 80);
|
||||
}
|
||||
|
||||
/**
|
||||
* Cap for a single logged request/response body before it gets replaced by a
|
||||
* bare {_truncated, _originalBytes, messageCount, ...} summary instead of the
|
||||
* full clone (open-sse/handlers/chatCore/logTruncation.ts::truncateForLog()).
|
||||
* Was a hardcoded 8KB — trivially exceeded by any real multi-turn agentic
|
||||
* conversation, which meant the dashboard's "Full Conversation" transcript
|
||||
* panel could only ever show a placeholder instead of the actual messages
|
||||
* for nearly every logged row. Bumped 128x (to 1MB) by default and exposed
|
||||
* as an operator override for anyone who needs it even larger (or smaller,
|
||||
* on a memory-constrained box) — see the same "protect memory across many
|
||||
* call sites per request" reasoning truncateForLog()'s own doc comment
|
||||
* explains for why some cap must still exist.
|
||||
*/
|
||||
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";
|
||||
|
||||
@@ -254,7 +254,11 @@ function ConversationTranscriptSection({
|
||||
<div className="flex items-center gap-2">
|
||||
<button
|
||||
onClick={toggleAutoFollow}
|
||||
title={autoFollow ? "Auto-follow: on (jumps to the next turn as soon as it lands)" : "Auto-follow: off"}
|
||||
title={
|
||||
autoFollow
|
||||
? "Auto-follow: on (jumps to the next turn as soon as it lands)"
|
||||
: "Auto-follow: off"
|
||||
}
|
||||
className={`p-1 rounded hover:bg-bg-subtle text-text-muted hover:text-text-primary transition-colors ${autoFollow ? "text-primary" : ""}`}
|
||||
aria-pressed={autoFollow}
|
||||
aria-label="Toggle auto-follow to next turn"
|
||||
@@ -955,6 +959,21 @@ export default function RequestLoggerDetail({
|
||||
<div className="text-sm text-text-muted">\u2014</div>
|
||||
)}
|
||||
</div>
|
||||
<div>
|
||||
<div className="text-[10px] text-text-muted uppercase tracking-wider mb-1">
|
||||
Conversation
|
||||
</div>
|
||||
{detail?.sessionTag || log.sessionTag ? (
|
||||
<div
|
||||
className="text-sm font-mono select-all"
|
||||
title={detail?.sessionTag || log.sessionTag}
|
||||
>
|
||||
{(detail?.sessionTag || log.sessionTag).slice(0, 20)}\u2026
|
||||
</div>
|
||||
) : (
|
||||
<div className="text-sm text-text-muted">\u2014</div>
|
||||
)}
|
||||
</div>
|
||||
</div>
|
||||
)}
|
||||
|
||||
|
||||
@@ -134,7 +134,7 @@ test("truncateForLog summarizes oversized payloads instead of cloning", () => {
|
||||
provider: "openai",
|
||||
stream: true,
|
||||
// distinct object references so estimateSizeFast (WeakSet-dedup) counts each one
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(64) })),
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(500) })),
|
||||
contents: [{ a: 1 }],
|
||||
};
|
||||
const summary = truncateForLog(huge) as Record<string, unknown>;
|
||||
@@ -159,11 +159,11 @@ test("truncateForLog captures a message count for Responses API bodies too (inpu
|
||||
const huge = {
|
||||
model: "gpt-5",
|
||||
stream: true,
|
||||
input: Array.from({ length: 400 }, () => ({ role: "user", content: "x".repeat(64) })),
|
||||
input: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(500) })),
|
||||
};
|
||||
const summary = truncateForLog(huge) as Record<string, unknown>;
|
||||
assert.equal(summary._truncated, true);
|
||||
assert.equal(summary.messageCount, 400);
|
||||
assert.equal(summary.messageCount, 50000);
|
||||
});
|
||||
|
||||
test("truncateForLog keeps a bounded `tools` field alive when the request is summarized", () => {
|
||||
@@ -200,7 +200,7 @@ test("truncateForLog keeps a bounded `tools` field alive when the request is sum
|
||||
model: "gpt-4o",
|
||||
provider: "openai",
|
||||
stream: true,
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(64) })),
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(500) })),
|
||||
tools,
|
||||
};
|
||||
|
||||
@@ -226,7 +226,7 @@ test("truncateForLog bounds an oversized `tools` array to the configured tail-it
|
||||
}));
|
||||
const huge = {
|
||||
model: "gpt-4o",
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(64) })),
|
||||
messages: Array.from({ length: 50000 }, () => ({ role: "user", content: "x".repeat(500) })),
|
||||
tools: manyTools,
|
||||
};
|
||||
|
||||
|
||||
@@ -1,9 +1,8 @@
|
||||
import test from "node:test";
|
||||
import assert from "node:assert/strict";
|
||||
|
||||
const { estimateSizeFast, isSmallEnoughForSemanticCache } = await import(
|
||||
"../../open-sse/utils/estimateSize.ts"
|
||||
);
|
||||
const { estimateSizeFast, isSmallEnoughForSemanticCache } =
|
||||
await import("../../open-sse/utils/estimateSize.ts");
|
||||
|
||||
test("estimateSizeFast returns 0 for null/undefined", () => {
|
||||
assert.equal(estimateSizeFast(null), 0);
|
||||
@@ -65,6 +64,31 @@ test("estimateSizeFast early-exits at 262144 bytes (256KB)", () => {
|
||||
assert.ok(result >= 262144, `Should early-exit, got ${result}`);
|
||||
});
|
||||
|
||||
test("estimateSizeFast accepts a custom earlyExitAt so a raised caller threshold is actually reachable", () => {
|
||||
// Bug: chatCore/logTruncation.ts's truncateForLog() compares estimateSizeFast's
|
||||
// result against a configurable threshold (getChatLogMaxBodyBytes(), default
|
||||
// 1MB) — but estimateSizeFast's own early-exit was hardcoded at 256KB. Many
|
||||
// small chunks (the realistic shape — a message array) stop accumulating the
|
||||
// instant the running total crosses the early-exit point, so with the old
|
||||
// hardcoded 256KB exit the reported size could never signal "still under a
|
||||
// 1MB threshold" for an object whose true size sits between the two.
|
||||
const chunks = Array.from({ length: 6000 }, () => "x".repeat(100)); // ~600KB true size
|
||||
const defaultResult = estimateSizeFast(chunks);
|
||||
assert.ok(
|
||||
defaultResult <= 262144 + 100,
|
||||
`default earlyExitAt should stop accumulating around 256KB, got ${defaultResult}`
|
||||
);
|
||||
const oneMbResult = estimateSizeFast(chunks, 1024 * 1024);
|
||||
assert.ok(
|
||||
oneMbResult > 262144,
|
||||
`with a 1MB earlyExitAt, ~600KB of chunks must be measurable past the old 256KB cap, got ${oneMbResult}`
|
||||
);
|
||||
assert.ok(
|
||||
oneMbResult <= 1024 * 1024 + 100,
|
||||
`should not exceed the true ~600KB size, got ${oneMbResult}`
|
||||
);
|
||||
});
|
||||
|
||||
test("estimateSizeFast handles mixed object/array nesting", () => {
|
||||
const data = {
|
||||
choices: [
|
||||
|
||||
Reference in New Issue
Block a user