Implement server.mjs debug logging - #190
Conversation
There was a problem hiding this comment.
Thanks for the contribution! Debug-logging surfaces are useful for the "I can't reproduce this" diagnostic class, and proxy/server.mjs is the right place to add one. Before I can take a formal position on the PR (approve or request-changes), there are several things I'd want to talk through. None of them are dealbreakers — the intent is sound — but they do need to be addressed before merge. Detail below, grouped by class of concern.
Tests pass on your branch, but...
npm test returns 907/907 on your branch. (Note: that's because your branch is based on 3c97e32 from v3.9.0 — main is now at 981/981 after #192 landed today. A rebase will be clean, no file overlap.) The full suite doesn't catch the runtime issues I'm about to flag because:
- The new code paths don't have new tests
- The unconditional logging fires below the test runner's noise floor
Real concerns
1. Unconditional console.log at module top-level (line 18-26 of new code)
console.log(`config.port='${config.port}'`);
console.log(`config.bind='${config.bind}'`);
// ... 7 moreThese fire on every import of proxy/server.mjs — including in tests, in production at boot, anywhere the module is imported. I verified by importing the module in a one-liner: it dumps 9 config values to stdout unconditionally, regardless of CACHE_FIX_DEBUG.
I think the intent was "log config at startup for diagnostic," but as written this is unconditional spam. Two options:
- Gate behind
if (config.debug)likedebugLog()already does (probably what you wanted) - Move into a dedicated startup log call that fires once per server-start, not once per import
Either way: this is a real concern, not a nit.
2. console.error("[PROXY] forwardRequest error: ...") at line 132 fires regardless of debug mode
} catch (err) {
console.error("[PROXY] forwardRequest error:", err.message);
debugLog("[PROXY] forwardRequest error:", err.message);Same shape as above — the console.error fires whether CACHE_FIX_DEBUG is on or not. The existing debugLog() call is the right channel; the console.error is redundant when debug is on, and noisy stderr in production when debug is off. Drop the console.error, keep the debugLog.
Same applies to the console.error calls in the new try/catch at line 351 ("!!! REQUEST HANDLER ERROR !!!").
3. res.url / res.method / res.statusMessage don't exist on response objects
Several of the new debugLog calls reference properties that don't exist on http.ServerResponse:
debugLog("url:", clientRes.url); // undefined — res has no .url
debugLog("method:", clientRes.method); // undefined — res has no .method
debugLog("message:", clientRes.statusMessage); // undefined on outbound resI verified empirically — res.url, res.method, res.statusMessage are all undefined on http.ServerResponse. These are req properties (or they exist on IncomingMessage for received responses). The log lines as written will emit url: undefined method: undefined message: undefined.
I think you wanted the corresponding clientReq properties, which are accessible because clientReq is in scope in handleMessages. Same likely applies to the upstreamRes lines lower down — those should probably be referencing clientReq.
4. res.write / res.end monkey-patching is more than logging
res.write = function (chunk, ...args) {
debugLog(`[PROXY -> CLAUDE] Send chunk. Size: ${chunk ? chunk.length : 0} bytes`);
return originalWrite.apply(res, [chunk, ...args]);
};
res.end = function (chunk, ...args) { ... };This pattern changes the behavior of every response, not just adds logging. The wrap is harmless in the common case but has a few sharp edges:
chunk.lengthmeasures bytes forBufferbut characters for strings. The log says "bytes" but isn't always bytes. UseBuffer.byteLength(chunk)if you want consistent byte counts.- Wrapping happens unconditionally even when
config.debugis false — same issue as #1 above. Every response goes through the wrapper for nothing. - This adds a function-call layer to every chunk write — measurable overhead on streaming responses if the proxy is under heavy load.
If you only want this logging when debug is on, gate the wrap behind if (config.debug).
5. The try/catch wrapping the entire request handler is a substantive behavior change
try { ... } catch (error) {
// Reply error 500 to prevent claude hanging
if (!res.headersSent) {
res.writeHead(500, { 'Content-Type': 'application/json' });
res.end(JSON.stringify({ error: "Internal Proxy Error", message: error.message }));
}
}This is actually a good idea on its own — proxies should not let exceptions crash the server. But it's a behavior change well beyond "add debug logging." If you want this, it deserves to be its own PR (or at least called out in this PR's description) so it gets reviewed on its own merits, not bundled into a logging change.
Specifically:
error.messageis leaked in the response body — for a corp-deployed proxy that's an information disclosure that may not be acceptable- The 500 fallback may mask bugs the existing code path would have surfaced (current behavior: uncaught throw → Node crashes → systemd restart → operator notices)
6. PR has no description
The PR body is empty. A community contribution's PR body is the place to say "I needed this to debug X" or "I want to see what's happening when Y." That context shapes the review and helps maintainers prioritize. Even one sentence helps.
Smaller things (would address with the above)
import util from 'util'uses default-import + single quotes while the rest of the file uses destructured imports + double quotes. Style nit.appendFileSync/readFileSync/writeFileSync/mkdirSync/renameSyncare imported but onlyappendFileSyncis used. Trim unused imports.- The new imports sit below
startWatcherimport rather than at the top of the file with everything else. Conventional style puts allimports in one block.
Disposition
I'm posting this as --comment rather than --request-changes because the intent of the PR is good and the issues are addressable. But the unconditional logging + the res.url/res.method confusion + the monkey-patching defaults are real concerns that need to be addressed before merge.
If you'd like, I can:
- Walk through specific patches for each numbered item, OR
- Push corrections to your branch (you have
maintainerCanModifyenabled), OR - Wait for you to iterate
I'll also trigger an independent Codex review next; he often catches things I miss. We'll synthesize both reads and come back to you with a consolidated path forward.
Thanks for picking up something useful — debug logging really is a gap in our diagnostic story. Looking forward to landing this once we work through the details.
— Proxy Builder
There was a problem hiding this comment.
Codex review:
-
proxy/server.mjs:321-323writes raw request headers to~/.claude/cache-fix-debug.log. On this proxy surface that can persistAuthorization/x-api-key, and the repo architecture docs say auth headers must never appear in logs. Please redact or drop header dumps before merge. -
proxy/server.mjs:29-37,132,347, and352-353add ungated stdout/stderr output even whenCACHE_FIX_DEBUGis off. For an embeddable module, debug surfaces need to stay behind the existing opt-in flag. -
proxy/server.mjs:317-359does not actually catch the async failures it claims to catch.handleMessages()andhandleBootstrap()are async, but the request callback returns their promises withoutawait, so rejections bypass thistry/catch. -
proxy/server.mjs:111-115,148-153, and328-335produce misleading diagnostics: the logged request/response fields are absent or semantically wrong on those objects, and the byte counters are socket-lifetime write counters rather than per-response payload sizes. For a debug PR, incorrect logs are a blocker. -
I checked the bootstrap-route question against current
main:/api/claude_cli/bootstrapis not duplicated by this PR. The route already exists onmain; this patch only re-houses that existing branch inside the new wrapper. -
If the 500 fallback stays in a future revision, please keep the client body generic rather than echoing
error.message.
Detailed artifact: docs/code-reviews/pr-190-server-debug-logging-codex-review-2026-06-04.md on branch consult/pr-190-codex-review at fba123d.
The intent of the contribution is good. I would welcome a narrowed follow-up that keeps the diagnostics opt-in, redacted, and behavior-preserving.
— Codex review
|
Codex's independent review surfaced two critical concerns I missed plus sharpened a third I'd flagged loosely. Crediting him because these reshape the path forward significantly: The big one I missed: Authorization headers in the debug logCodex flagged: Fix shape: redact function redactHeaders(headers) {
const out = {};
for (const [k, v] of Object.entries(headers)) {
const lc = k.toLowerCase();
out[k] = (lc === "authorization" || lc === "x-api-key" || lc.startsWith("cookie")) ? "[REDACTED]" : v;
}
return out;
}This blocker needs to land before any version of this PR is merged. It's the most important thing on the list. The try/catch doesn't actually catch what you wantedI flagged the try/catch as "a substantive behavior change beyond logging" in my original review, but Codex caught something I missed: In other words, the catch as written wraps only the synchronous routing decision (which already couldn't throw), not the actual request-handler bodies. The "prevent claude hanging" intent doesn't work. If you want this containment, the shape is: const handler = req.method === "POST" && req.url?.startsWith("/v1/messages")
? handleMessages
: ...;
void handler(req, res).catch((err) => {
debugLog("[PROXY] handler rejected:", err.message);
if (!res.headersSent) {
res.writeHead(500, { 'Content-Type': 'application/json' });
res.end(JSON.stringify({ error: "Internal Proxy Error" })); // generic — don't leak err.message
}
});But as Codex notes, that's a separate change from "add debug logging." It deserves its own PR with its own review. The bytes/url/method confusions are deeper than my first readCodex confirmed what I flagged (
So three of the diagnostic fields don't measure what their labels say. A debug feature whose output misstates the request/response shape sets up future bug reports based on misread logs. Consolidated path forwardI think the cleanest way to land something useful here is to scope this PR down to just the opt-in
What's left after that is a small, focused, opt-in diagnostic that's safe to ship. How I can helpThree options, your choice:
The intent of the PR is genuinely useful — debug logging IS a gap in cache-fix's diagnostic story. The current implementation just has more rough edges than I can approve. Looking forward to landing this once we work through it. — Proxy Builder |
…c 500 (cnighswonger#190 round 2) Addresses Codex round-1 review (2026-06-04T21:43Z, CHANGES_REQUESTED): 1. Authorization / x-api-key / cookie / proxy-authorization redacted in debug log via a small redactHeaders() helper. Same discipline as bootstrap-defense.mjs's audit-record contract: never spread raw headers to log code. [REDACTED] sentinel preserves "header was present" signal. 2. Gated all stdout/stderr behind CACHE_FIX_DEBUG. Removed the nine module-top console.log(config.X) lines (fired on every import, embedder-hostile) and the four ungated console.error() calls in the dispatcher / forwardRequest catch. All debug surfaces now flow through debugLog, which self-gates on process.env.CACHE_FIX_DEBUG === "1". 3. Dispatcher now awaits handleMessages / handleBootstrap inside an async IIFE wrapped by try/catch — rejections from preForward() or pipeline hooks no longer escape to unhandledRejection. 4. Fixed two misleading diagnostics: clientRes.url / .method are undefined (those are request fields); replaced with clientReq.method / .url in the pre.handled branch. Removed the bytesWritten lines (those are socket-lifetime counters, not per-response payloads). 5. 500 fallback body is generic ({"error":"internal_proxy_error"}) — no longer echoes error.message, which could leak internal paths or upstream URLs. Also: - Removed unused fs imports (readFileSync/writeFileSync/renameSync). - Wired mkdirSync for log-dir bootstrap (was imported but unwired). - LOG_PATH now overridable via CACHE_FIX_DEBUG_LOG for test isolation. - Live env read on every debugLog call (matches image-strip's cnighswonger#98 gate). Test coverage in test/proxy-server-debug-log.test.mjs: - /health hit with debug off creates no log file (no-noise control) - Authorization / x-api-key / cookie / proxy-authorization all redact - Non-sensitive header values still appear (over-redaction guard) - Module import produces no stdout when CACHE_FIX_DEBUG unset (spawn child) - Static: 500 body has no error.message echo; dispatcher awaits handlers Co-authored-by: Aleksandr Usenko <nisqatsi@users.noreply.github.com>
2b73759 to
8c4c2de
Compare
|
@nisqatsi — Chris cleared us to land this rather than block on iterations, since you've been moving fast on #188 and #189. I pushed Headline changes in
Bonus:
New test file
Full suite green (1029/1029) at Next: re-delegating Codex round 2. If approved, I'll wait for Diff: https://github.com/cnighswonger/claude-code-cache-fix/pull/190/files — Proxy Builder |
There was a problem hiding this comment.
Review: PR #190 server debug logging
Date: 2026-06-08
Reviewed: PR #190 at 8c4c2de
Round: 2
Label applied: approved-by-codex-agent
What Is Correct
- The security blocker is closed. Sensitive header names now live in a lowercase denylist that includes
authorization,x-api-key,cookie,set-cookie, andproxy-authorization, andredactHeaders()case-folds every key before deciding whether to emit[REDACTED](proxy/server.mjs:26,proxy/server.mjs:34,proxy/server.mjs:37). Every debug log call that emits headers now routes through that helper (proxy/server.mjs:122,proxy/server.mjs:152,proxy/server.mjs:153,proxy/server.mjs:337). The targeted coverage also exercises Authorization, x-api-key, cookie, proxy-authorization, and the non-sensitive control case (test/proxy-server-debug-log.test.mjs:116,test/proxy-server-debug-log.test.mjs:139,test/proxy-server-debug-log.test.mjs:159,test/proxy-server-debug-log.test.mjs:175). - The ungated stdout/stderr regression is closed.
debugLog()is now a no-op unlessCACHE_FIX_DEBUG === "1"(proxy/server.mjs:42,proxy/server.mjs:43), and the module-import child-process test asserts zero stdout when the flag is unset (test/proxy-server-debug-log.test.mjs:196). I also verifiedgrep -nE 'console\\.(log|error)' proxy/server.mjsreturns no matches on this head. - The async rejection containment bug is closed.
createProxyServer()now wraps dispatch in an async IIFE and explicitlyawaits both async route handlers inside the surroundingtry/catch(proxy/server.mjs:333,proxy/server.mjs:354,proxy/server.mjs:355,proxy/server.mjs:358). The 500 fallback body is now the constant generic sentinel{ "error": "internal_proxy_error" }, with noerror.messageecho (proxy/server.mjs:360,proxy/server.mjs:364). The new structural checks cover both requirements (test/proxy-server-debug-log.test.mjs:230,test/proxy-server-debug-log.test.mjs:254). - The misleading diagnostics called out in round 1 are corrected. The internal-handled path now logs
clientReq.method/clientReq.url, not nonexistent response-object request fields (proxy/server.mjs:119,proxy/server.mjs:120). The upstream response log still usesupstreamRes.statusMessage, which is the right object for that field, and I found no remainingclientRes.url,clientRes.method, orbytesWrittenreferences inproxy/server.mjsat this head (proxy/server.mjs:150,proxy/server.mjs:151). - Verification is strong enough for approval.
node --test test/proxy-server-debug-log.test.mjspassed8/8, andnpm testpassed1029/1029locally on8c4c2dee3857cbbe049270e2a6749cd6394afd9c.
Blockers
None.
What Needs Attention
None.
Bloat / Non-Functional
None.
Recommendations
- Optional only: if you want a simpler white-box probe for the redaction helper later, export a small test seam for
redactHeaders(). The current integration and structural coverage is sufficient for this PR without it.
Bottom Line
The five round-1 blockers are closed on the maintainer-edited head. Secrets are redacted before any header dump reaches disk, the new debug surface is back behind the opt-in gate, the dispatcher now actually catches awaited async-handler failures, the misleading request/response diagnostics are fixed, and the 500 fallback is generic. With the new targeted coverage and a clean 1029/1029 full-suite run, this is ready for approval.
— Codex review
There was a problem hiding this comment.
Refreshing my review state — my round-1 COMMENTED review was at 2b73759, which is now stale.
Approving at d8a03d7 (Codex's round-2 review-doc commit on top of my 8c4c2de fix). All five Codex round-1 blockers closed empirically — see Codex's round-2 review for the file:line evidence and the docs/code-reviews/pr-190-round-2-codex.md artifact on this branch. npm test 1029/1029 green, all 3 CI Node matrices SUCCESS, GitGuardian + Snyk green.
Marking approved-by-code-agent. Author attribution preserves as @nisqatsi on squash-merge.
— Proxy Builder
No description provided.