Skip to content

feat: Log one access line per request - #19

Merged
harshaneel merged 3 commits into
mainfrom
hg/request-logging
Aug 6, 2026
Merged

feat: Log one access line per request#19
harshaneel merged 3 commits into
mainfrom
hg/request-logging

Conversation

@harshaneel

Copy link
Copy Markdown
Owner

Summary

  • The proxy was silent between its startup and shutdown lines, so there was no way to see what happened to a request. It now logs one access line per request: method, path, status, and latency.
localaik  POST /v1/chat/completions  200  412.183ms
localaik  POST /v1beta/models/gemma:generateContent  200  1.204s
localaik  POST /v1/messages  502 Bad Gateway  8.41ms
localaik  GET /nope  404 Not Found  59µs
  • Implemented as a middleware (WithRequestLog) that wraps the handler, so none of the ~12 routes had to change. A statusRecorder captures the status while preserving http.Flusher, so SSE streaming still flushes.
  • On by default. LK_LOG=off silences the per-request lines (startup lines stay). Only off disables it; 0 and false leave it on, which the README notes.
  • Headers and bodies are never logged, consistent with the credential-redaction work already in main. Successful /health probes are skipped, since the container healthcheck hits them every few seconds; a failing /health still logs.

Review found a real security issue, now fixed

Three reviews ran. The notable catch (from the Codex pass, missed by the other two): log injection. r.URL.Path is the decoded path, so a request to /x%0A... would put a raw newline or ANSI escape into the log line, letting anyone who can reach the port forge log entries or inject terminal escapes (CWE-117). Fixed: any method or path containing a control character is quoted before logging. Also hardened from review: only the first WriteHeader/implicit-200 is recorded (so the logged status matches what the client got), and the line is emitted from a defer so a panicking handler still logs.

Deliberately out of scope

  • http.Hijacker / io.ReaderFrom are not forwarded by the wrapper. localaik is HTTP + SSE only, with no hijack or upgrade path, and all three reviews confirmed zero current or perf impact (the io.Copy fast path is already unreachable in production because the real writer is always a Flusher). Adding net/bufio plumbing for unused interfaces would be speculative complexity. Noted here as a conscious YAGNI omission, trivial to add if a future feature ever needs it.
  • RedactUpstream keeps a path-based credential in the upstream URL (a pre-existing edge in already-merged code, unrelated to logging). Tracked as a separate follow-up.

Test Plan

  • make lint clean, all unit tests pass. 13 middleware tests cover the access line, error-status text, implicit and explicit status capture (first wins), Flusher preservation, health skip (success suppressed, failure logged), no-header-leak, control-char sanitization, and the nil-logger disable path. requestLoggingEnabled is table-tested.
  • The docker_integration ProxyImage test passes.
  • Verified live against a real llama.cpp: access lines print for every route; SSE streaming still delivers frames; a crafted %0A path logs as a single quoted line with the newline escaped (no forgery); /health spam is suppressed; LK_LOG=off silences per-request lines while startup lines remain.

🤖 Generated with Claude Code

harshaneel and others added 2 commits August 5, 2026 23:02
The proxy was silent between startup and shutdown, so there was no way to
see what happened to a request. It now logs method, path, status, and
latency per request through a middleware that wraps the handler, so no route
had to change.

The status-capturing wrapper still exposes http.Flusher, so SSE streaming
keeps flushing. Headers and bodies are never logged, keeping credentials and
prompts out of the log. Successful /health probes are skipped, since the
container healthcheck hits them every few seconds. LK_LOG=off silences the
per-request lines.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
- Sanitize the method and path before logging. A decoded request path can
  carry control characters, so a crafted path could otherwise forge log lines
  or inject terminal escapes. Values with control characters are now quoted.
- Record only the first WriteHeader, matching net/http, so the logged status
  is the one the client received.
- Log from a deferred call, so a panicking handler still leaves an access line.
- Extract requestLoggingEnabled so the LK_LOG semantics are unit-tested, and
  document that only "off" disables logging.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
The path already determined the protocol, but reading it off /v1/messages
versus /v1/chat/completions took a second look. Each access line now leads
with [openai], [gemini], or [anthropic] (or [-] for a non-API path), from a
protocolLabel helper that mirrors the routing in ServeHTTP.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@harshaneel
harshaneel merged commit 0d406d9 into main Aug 6, 2026
3 checks passed
@harshaneel harshaneel mentioned this pull request Aug 6, 2026
2 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant