diff --git a/.env.example b/.env.example index 63a23d8801..189d12a11d 100644 --- a/.env.example +++ b/.env.example @@ -1414,7 +1414,7 @@ APP_LOG_TO_FILE=true # Whether call log pipeline capture stores stream chunks when enabled in settings. # Only applies when call_log_pipeline_enabled=true. -# Default: true +# Default: false (opt-in — saves disk: stream chunks are the biggest call-log artifact) # CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS=true # Maximum call log artifact size for pipeline captures, in KB. @@ -1893,7 +1893,7 @@ APP_LOG_TO_FILE=true # Log request shape (content-type + content-length) for large chat payloads. # Used by: src/app/api/v1/chat/completions/route.ts. Set to "0" to silence. -# Default: enabled. +# Default: disabled (opt-in). # OMNIROUTE_LOG_REQUEST_SHAPE=1 # Write raw (untruncated) request/response JSON in call log artifacts. diff --git a/docs/reference/ENVIRONMENT.md b/docs/reference/ENVIRONMENT.md index 4669c5f9a0..3f319dde03 100644 --- a/docs/reference/ENVIRONMENT.md +++ b/docs/reference/ENVIRONMENT.md @@ -736,7 +736,7 @@ The logging system writes to both stdout and rotated log files. All configuratio | `CALL_LOGS_TABLE_MAX_ROWS` | `100000` | Max rows in the `call_logs` SQLite table before pruning. | | `ENABLE_REQUEST_LOGS` | _(unset)_ | Force detailed request logging on or off, overriding the dashboard setting. | | `MAX_PENDING_REQUEST_AGE_MS` | `3600000` (1 hour) | Max age for orphaned active request log entries before in-memory cleanup. | -| `CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS` | `true` | Store stream chunks in pipeline artifacts when `call_log_pipeline_enabled=true`. | +| `CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS` | `false` | Store stream chunks in pipeline artifacts when `call_log_pipeline_enabled=true`. Opt-in (`true`) — off by default to save disk. | | `CALL_LOG_PIPELINE_MAX_SIZE_KB` | `512` | Max pipeline call log artifact size in KB when `call_log_pipeline_enabled=true`. | | `PROXY_LOGS_TABLE_MAX_ROWS` | `100000` | Max rows in the `proxy_logs` SQLite table before pruning. | | `APP_LOG_ROTATION_CHECK_INTERVAL_MS` | `60000` (1 min) | How often `src/lib/logRotation.ts` re-checks the active log file size. | @@ -976,7 +976,7 @@ changing them requires a code edit, not an env var: | `CURSOR_AGENT_CLI_VERSION` | _(detect / pin)_ | `open-sse/utils/cursorAgentCliVersion.ts` | Agent CLI build id (`YYYY.MM.DD-`) for `x-cursor-client-version: cli-…` on Agent Run. | | `CURSOR_DATA_DIR` | _(probed)_ | `open-sse/utils/cursorAgentCliVersion.ts` | Override Cursor Agent CLI data dir (`…/versions/`); same var the official agent uses. | | `CURSOR_TOKEN` | _(unset)_ | `scripts/ad-hoc/cursor-tap.cjs` | Direct Cursor bearer token used by developer tooling. | -| `OMNIROUTE_LOG_REQUEST_SHAPE` | enabled (`!== "0"`) | `src/app/api/v1/chat/completions/route.ts` | Log content-type/length markers for large chat payloads. Set `"0"` to silence. | +| `OMNIROUTE_LOG_REQUEST_SHAPE` | disabled (opt-in via `"1"`) | `src/app/api/v1/chat/completions/route.ts` | Log content-type/length markers for large chat payloads when `"1"` is set. Off by default to reduce log noise. | | `DEBUG_RESPONSES_SSE_TO_JSON` | _(unset)_ | `open-sse/handlers/responseTranslator.ts` | Set `true` to log Responses API SSE→JSON translation details. | | `NEXT_PUBLIC_OMNIROUTE_E2E_MODE` | _(unset)_ | E2E test harness | Set `true` to enable E2E test mode (relaxed auth, test hooks). | diff --git a/src/app/api/v1/chat/completions/route.ts b/src/app/api/v1/chat/completions/route.ts index e61ec10603..36ae77c107 100644 --- a/src/app/api/v1/chat/completions/route.ts +++ b/src/app/api/v1/chat/completions/route.ts @@ -84,6 +84,7 @@ export async function POST(request) { // OpenAI/Anthropic reject `text/plain` or missing Content-Type at the edge; matching // that behavior prevents a text/plain body from silently reaching provider lookup. const contentType = request.headers.get("content-type") ?? ""; + const requestContentLengthHeader = request.headers.get("content-length"); if (!contentType.toLowerCase().split(";")[0].trim().startsWith("application/json")) { return new Response( JSON.stringify({ @@ -112,10 +113,10 @@ export async function POST(request) { try { // One-line marker for diagnosing 413 / Server-Action interceptions. // Logs only when Content-Length is present so debug noise stays low for - // typical chat payloads. Toggle off via OMNIROUTE_LOG_REQUEST_SHAPE=0. - if (process.env.OMNIROUTE_LOG_REQUEST_SHAPE !== "0") { - const ct = request.headers.get("content-type") ?? ""; - const cl = request.headers.get("content-length"); + // typical chat payloads. Opt-in via OMNIROUTE_LOG_REQUEST_SHAPE=1. + if (process.env.OMNIROUTE_LOG_REQUEST_SHAPE === "1") { + const ct = contentType; + const cl = requestContentLengthHeader; if (cl && Number(cl) > 256 * 1024) { console.error(`[CHAT-ROUTE] large body content-type="${ct}" content-length=${cl}`); } diff --git a/src/lib/logEnv.ts b/src/lib/logEnv.ts index 95e9428aa6..c99cf1f209 100644 --- a/src/lib/logEnv.ts +++ b/src/lib/logEnv.ts @@ -116,7 +116,7 @@ export function getCallLogsTableMaxRows(): number { } export function getCallLogPipelineCaptureStreamChunks(): boolean { - return parseBoolean(process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS, true); + return parseBoolean(process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS, false); } export function getCallLogPipelineMaxSizeBytes(): number { diff --git a/tests/unit/logging-opt-in-defaults.test.ts b/tests/unit/logging-opt-in-defaults.test.ts new file mode 100644 index 0000000000..5fcd132901 --- /dev/null +++ b/tests/unit/logging-opt-in-defaults.test.ts @@ -0,0 +1,75 @@ +import assert from "node:assert/strict"; +import test from "node:test"; + +import { POST } from "../../src/app/api/v1/chat/completions/route.ts"; +import { getCallLogPipelineCaptureStreamChunks } from "../../src/lib/logEnv.ts"; + +const originalConsoleError = console.error; +const originalCaptureChunks = process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS; +const originalRequestShape = process.env.OMNIROUTE_LOG_REQUEST_SHAPE; + +test.afterEach(() => { + console.error = originalConsoleError; + + if (originalCaptureChunks === undefined) { + delete process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS; + } else { + process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS = originalCaptureChunks; + } + + if (originalRequestShape === undefined) { + delete process.env.OMNIROUTE_LOG_REQUEST_SHAPE; + } else { + process.env.OMNIROUTE_LOG_REQUEST_SHAPE = originalRequestShape; + } +}); + +test("stream-chunk pipeline capture is disabled by default and supports explicit opt-in", () => { + delete process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS; + assert.equal(getCallLogPipelineCaptureStreamChunks(), false); + + process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS = "true"; + assert.equal(getCallLogPipelineCaptureStreamChunks(), true); + + process.env.CALL_LOG_PIPELINE_CAPTURE_STREAM_CHUNKS = "false"; + assert.equal(getCallLogPipelineCaptureStreamChunks(), false); +}); + +async function requestShapeMarkers(value: string | undefined): Promise { + if (value === undefined) { + delete process.env.OMNIROUTE_LOG_REQUEST_SHAPE; + } else { + process.env.OMNIROUTE_LOG_REQUEST_SHAPE = value; + } + + const markers: string[] = []; + console.error = (...args: unknown[]) => { + const message = args.map(String).join(" "); + if (message.includes("[CHAT-ROUTE] large body")) markers.push(message); + }; + + const body = JSON.stringify({ + messages: [{ role: "user", content: "x".repeat(300 * 1024) }], + }); + const response = await POST( + new Request("http://localhost/v1/chat/completions", { + method: "POST", + headers: { + "content-length": String(Buffer.byteLength(body)), + "content-type": "application/json", + }, + body, + }) + ); + await response.text(); + return markers; +} + +test("large-request shape logging requires the exact opt-in value 1", async () => { + assert.deepEqual(await requestShapeMarkers(undefined), []); + assert.deepEqual(await requestShapeMarkers("true"), []); + + const enabledMarkers = await requestShapeMarkers("1"); + assert.equal(enabledMarkers.length, 1); + assert.match(enabledMarkers[0], /content-length=3072\d\d/); +});