Skip to content

feat(logging): extract access log middleware with injectable sinks - #190

Merged
jonbaldie merged 1 commit into
mainfrom
feat/151-access-logging
Oct 27, 2026
Merged

jonbaldie merged 1 commit into
mainfrom
feat/151-access-logging

Conversation

@jonbaldie

Copy link
Copy Markdown
Owner

Summary

Callers can record or silence access logs without replacing process streams. Closes #151.

 createHandler(manager, token, rateLimit, logger?)
-  encode and write access logs directly
+  withLogging(logger)
     rate limit
       authenticate
         route Queue requests

 main lifecycle logs
-  separate encoder and writer
+  DEFAULT_CONSOLE_SINK

The default format, stream destinations, and middleware order stay unchanged. This does not add log levels or change logging-failure policy.

Evidence

  • Before: deno test --no-check tests/logging_test.ts failed. The custom sink received [] instead of the four expected health, authentication, and rate-limit records.
    After: deno test --allow-read --allow-write --allow-net --allow-env --allow-run passed all 395 tests. New checks cover custom and silent sinks, UTF-8 stream output, sync and async failures, and unchanged responses.
  • Before: Real HTTP requests logged to the hardcoded default streams.
    After: The compiled queue binary preserved health, authentication, enqueue, dequeue, missing-route logs, and graceful shutdown in a live HTTP smoke run.
  • deno run --frozen --allow-run scripts/compile.ts and npm run quality:production passed. The new tests also join the Mutasaurus test list.

Merge Danger

Door: two-way

A revert restores the original logging wrapper. No storage or configuration migration.

Blast Radius: logging

The shared HTTP middleware and lifecycle output change. Existing three-argument callers retain default logging and promise responses.

@jonbaldie

Copy link
Copy Markdown
Owner Author

Independent shipping verification for PR #190

Verdict PASS+NOTES. No code defects found in the pinned patch. The compiled head artifact and focused tests passed. The requested worktree switch and leave-at-head step are blocked by read-only Git metadata. This limitation remains open.

Reviewed #190 against #151.

  • Base SHA 569e6efbfa6f815dd5b332b8a6dc195b1aa54317.
  • Head SHA 7d56f71c919bbdebb4439d49dc2b5c41fc00cd59.
  • Computed stable patch-id 772ec7f7a5fe9bcd2c6544c0e2c8f5d3252fdb66. Matches the expected value.
  • Reviewer model gpt-6.1-sol, provider openai, OpenAI Codex CLI 0.164.0, reasoning effort high. Read directly from this review session's CLI header. Evidence in cli-identity.txt.
  • Runtime Deno 2.7.6. Used /home/ubuntu/Code/pstack/.audit/queue-151/tools first on PATH and DENO_DIR=/home/ubuntu/Code/pstack/.audit/queue-151/deno-cache for every Deno check.

Findings

No actionable correctness or compatibility findings.

Read AGENTS.md, issue #151, PR metadata, the complete pinned diff, and all six changed files. Also traced the unchanged router, limiter, configuration, manager, and relevant FileStore operations.

Existing two and three argument callers retain (Request, info?) => Promise<Response>. The fourth logger argument is optional. withLogging retains a concrete async return type while accepting synchronous or asynchronous downstream handlers. The independent script checks these assignments with Deno type checking enabled.

The dispatch order remains logging, rate limiting, authentication, then routing. The focused tests exercise real Request objects, including 401 before exhaustion, 429 after exhaustion, and public health handling. Default logging retains method, full URL, status, a space, two decimal places, and ms. A returned HTTP 500 goes to stdout. A synchronous throw or asynchronous rejection goes to stderr and propagates unchanged when the sink succeeds.

The new regression tests observe executed behavior. The custom sink test calls the real createHandler and checks concrete statuses and emitted records. The silent sink test launches a real Deno child process, calls createHandler, validates the health response body, and checks both captured streams. The default sink test executes production withLogging and captures real stdout and stderr for returned 500 and thrown errors. These assertions would fail if the subject returned undefined or logging reverted to unconditional process output. The response and error identity tests execute the middleware directly. Recording and silent sinks implement the new public interface without replacing globals or mocking the router or manager.

The independent edge check also verifies delayed completion, response identity and body preservation, and propagation of object, string, and undefined failures for synchronous and asynchronous handlers. A real FileStore configured with a file where a directory is required produces a real filesystem failure through createHandler. It emits one error record and leaves the queue empty.

Lifecycle output uses DEFAULT_CONSOLE_SINK. Persistent startup and shutdown checks verify the existing loading and flushing messages, their extra blank lines, successful restart, and a persisted payload round trip. The Mutasaurus test list includes logging_test.ts. I did not run mutation engines or use CI status as evidence.

Sink write failures retain the existing policy of propagating logging failures. This patch does not promise to preserve an earlier handler error when the sink itself throws.

Commands and measured outcomes

Every command and its actual output is captured under /home/ubuntu/Code/pstack/.audit/queue-151/review. The run-review.py helper records cwd, argv, DENO_DIR, output, and exit status.

Base commands ran in /home/ubuntu/Code/pstack/.worktrees/queue-151-review at the exact base SHA.

export PATH=/home/ubuntu/Code/pstack/.audit/queue-151/tools:$PATH
export DENO_DIR=/home/ubuntu/Code/pstack/.audit/queue-151/deno-cache
deno --version
deno run --frozen --allow-run scripts/compile.ts
python3 /home/ubuntu/Code/pstack/.audit/queue-151/http-smoke.py "$PWD" ./queue
python3 /home/ubuntu/Code/pstack/.audit/queue-151/review/persistent-smoke.py "$PWD"

All exited 0. Evidence in deno-version.log, base-compile.log, base-http-smoke.log, and base-persistent-smoke.log. The required smoke script observed health 200, unauthenticated queues 401, enqueue 200, dequeue 200 with the expected payload, missing route 404, five access logs with two decimal places, empty stderr, and graceful shutdown.

The attempted switch used exactly this command.

git switch --detach 7d56f71c919bbdebb4439d49dc2b5c41fc00cd59

It exited 128. Git could not create /home/ubuntu/Code/pstack/jonbaldie/queue/.git/worktrees/queue-151-review/index.lock because the filesystem is read-only. Evidence in switch-to-head.log. A subsequent compile in the same shell rebuilt base and is explicitly retained as base-recompile-after-blocked-switch.log. It is not head evidence.

To continue without changing protected metadata or another checkout, I created head.tar with git archive of the pinned head and extracted it into the permitted review directory at head-source. All 274 tracked file blobs match that exact commit. Evidence in git-evidence.json.

Head commands ran in /home/ubuntu/Code/pstack/.audit/queue-151/review/head-source.

deno run --frozen --allow-run scripts/compile.ts
deno test --frozen --allow-read --allow-write --allow-net --allow-env --allow-run tests/logging_test.ts tests/handler_test.ts
python3 /home/ubuntu/Code/pstack/.audit/queue-151/http-smoke.py "$PWD" ./queue
python3 /home/ubuntu/Code/pstack/.audit/queue-151/review/persistent-smoke.py "$PWD"

All exited 0. The focused run passed 149 tests, including all five logging tests and 144 handler tests. Evidence in head-compile.log, head-focused-tests.log, head-http-smoke.log, and head-persistent-smoke.log. The head smoke script observed the same five expected HTTP outcomes, access log format, empty stderr, and shutdown behavior as base. All application network requests stayed on loopback ephemeral ports.

The independent check imported head snapshot modules.

deno run --check --frozen --allow-read --allow-write /home/ubuntu/Code/pstack/.audit/queue-151/review/edge-check.ts

It exited 0. Evidence in edge-check.ts and head-edge-check.log. Its first run found TypeScript narrowing errors in my assertion helper, before executing application code. I corrected only that review artifact and retained the failed check as head-edge-check-first-typecheck.log. No patch file changed.

Remaining operational note and artifacts

The requested worktree still reports the exact base SHA 569e6efbfa6f815dd5b332b8a6dc195b1aa54317. I could not leave it at head because its Git metadata is read-only. The parent must switch it to 7d56f71c919bbdebb4439d49dc2b5c41fc00cd59 outside this sandbox. The head compile, focused tests, and smoke checks above ran on the verified archive, not on a switched worktree.

No tracked production or test file was edited. No commit, push, merge, or label change was made. The only artifact created inside the requested worktree is the ignored compiled base executable /home/ubuntu/Code/pstack/.worktrees/queue-151-review/queue. It can be removed by the parent. All other new review artifacts, including the head snapshot and its compiled executable, are under /home/ubuntu/Code/pstack/.audit/queue-151/review.

Prove It Works led to actual compiled CLI checks on both revisions. Test Behavior, Not Implementation led to inspection of executed responses and real process streams. Build the Lever led to the rerunnable review driver, edge check, and persistent smoke script. Sequence Work into Verifiable Units led to capturing the base before attempting the head transition. These principle leaf skills were read in this session. The user's no-agent and no-edit constraints took precedence over skill delegation and edit suggestions.

@jonbaldie
jonbaldie merged commit 584fe21 into main Oct 27, 2026
4 checks passed
@jonbaldie
jonbaldie deleted the feat/151-access-logging branch October 27, 2026 10:47
@jonbaldie

Copy link
Copy Markdown
Owner Author

Merged as 584fe21401ce9761ed706cf353b56bb74e4d5146 after all four CI checks passed. Issue #151 is closed.

The independent review's operational note is resolved: the parent successfully switched the detached review worktree to the pinned head after verification. The independently tested archive matched all 274 tracked head files, and the merge tree matches that reviewed head. Both session worktrees and build outputs are now removed; the original checkout is clean and synchronized with origin/main.

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.

Architecture: Decouple HTTP access logging from createHandler into a composable logging middleware seam

1 participant