Files
reverse-proxy/tasks/fix/access-logging.md
glm-5.1 f9d7b8112b Decompose implementation review fixes into 14 atomic tasks with post-fix review
Break down findings from review #002 into dependency-ordered fix tasks:

Critical/High:
- fix/acme-contact-and-challenge (C1+C2): Add acme_contact field, wire to
  ACME, remove unused challenge_config, add validation rule 19
- fix/remove-health-and-hardcode-https (W5+W14+ADR-022): Remove /health
  from main listener, hardcode X-Forwarded-Proto to https
- fix/config-reload-static-drift (C4): Use ArcSwap<StaticConfig> so reload
  diffs against last config, not startup config
- fix/access-logging (W13): Wire up log_request! macro for every proxied
  request with client_ip, host, method, path, status, upstream, duration_ms

Medium:
- fix/graceful-shutdown (W1+W7): Join HTTPS tasks with timeout instead of
  abort, add shutdown signal to admin socket and eviction task
- fix/connect-timeout (W4): Wire upstream_connect_timeout_secs to enforce
  separate connect timeout

Low/Independent:
- fix/token-bucket-nanosecond (W6): Use as_nanos() instead of as_millis()
- fix/normalize-host-ipv6 (S3): Handle IPv6 bracket notation in normalize_host
- fix/http-port-validation (S1): Validate http_port in range 0 or 1-65535
- fix/integration-test-toml (S10): Fix double-nested listeners.listeners.sites
- fix/logging-test-global-subscriber (W9): Use try_init() to avoid test conflicts
- fix/fragile-error-detection (W3): Add typed error matching or documented string match
- fix/add-code-comments (C3,W8,W10,W11,S9): Document correct-but-non-obvious behaviors
- fix/request-timeout-scope (S8): Document full-request timeout scope
- fix/clean-dead-code (S4+S2): Remove dead_code annotations, add #[non_exhaustive]

Review gate:
- review/post-fix-review: Verify all fixes against architecture spec
2026-06-12 04:08:45 +00:00

77 lines
3.1 KiB
Markdown

---
id: fix/access-logging
name: Wire up request access logging in the proxy handler
status: pending
depends_on: []
scope: moderate
risk: medium
impact: component
level: implementation
review_findings: [W13]
---
## Description
The `log_request!` macro exists in `src/logging/format.rs` but is never called anywhere in the codebase. The architecture spec (operations.md) states: "Access logging is **always-on** — it is the primary observability mechanism for the proxy and is required for fail2ban integration. There is no configuration option to disable access logging."
Every proxied request must produce an access log line in the format:
```
REQUEST client_ip=203.0.113.50 host=git.alk.dev method=GET path=/user/repo status=200 upstream=127.0.0.1:3000 duration_ms=45
```
Additionally, upstream errors must produce `UPSTREAM_ERROR` log lines and rate-limited requests already produce `RATE_LIMIT` lines (those work correctly).
### Changes Required
**`src/proxy/handler.rs`**:
- Add `std::time::Instant` tracking at the start of `proxy_handler`
- Call `log_request!` macro on every proxied request (success path)
- Include: `client_ip`, `host`, `method`, `path`, `status`, `upstream`, `duration_ms`
- Call `log_upstream_error!` on upstream connection failures and bad gateway errors
- The `duration_ms` should measure from request entry to response sent
**`src/proxy/mod.rs`**:
- Ensure `log_request!` and `log_upstream_error!` macros are accessible (they should be via `crate::log_request!`)
### Log Format Details
From operations.md and the existing macro definitions:
**Access log** (every proxied request):
```
REQUEST client_ip=203.0.113.50 host=git.alk.dev method=GET path=/user/repo status=200 upstream=127.0.0.1:3000 duration_ms=45
```
**Upstream error** (connection refused, timeout, etc.):
```
UPSTREAM_ERROR host=git.alk.dev upstream=127.0.0.1:3000 error="connection refused"
```
The `log_upstream_error!` macro should be called in the error branches of `proxy_handler` where upstream connections fail or time out.
## Acceptance Criteria
- [ ] `log_request!` is called for every successfully proxied request
- [ ] `log_request!` is called for proxied requests that receive non-2xx upstream responses (4xx/5xx from upstream are still logged as access logs with the upstream status code)
- [ ] `log_upstream_error!` is called when upstream is unreachable (502)
- [ ] `log_upstream_error!` is called when upstream times out (504)
- [ ] `duration_ms` accurately measures request-to-response time
- [ ] Log format matches the `REQUEST` prefix format with `key=value` pairs
- [ ] Access logging is always-on — no configuration to disable it
- [ ] Existing tests pass
- [ ] `cargo clippy` passes with no warnings
## References
- docs/architecture/operations.md — logging section, access log format
- docs/reviews/002-implementation-review.md — W13 finding
- src/logging/format.rs — log_request!, log_upstream_error! macros
- docs/architecture/decisions/007-custom-log-format.md — log format rationale
## Notes
> To be filled by implementation agent
## Summary
> To be filled on completion