feat(observability): enrich core proxy logs with transaction context

[arnaugiralt]

Summary

Improves structured logging across the core proxy to make every log line actionable without needing to cross-reference other sources.

• Richer access log — RequestLoggerMiddleware now emits marketplace_id, product_id, and target_host (host only, path and query stripped) alongside the existing vendor_id. Header name strings are pre-computed once at construction rather than concatenated per request.
• Consistent operational logs — All warn/error/info log lines in the proxy that carry vendor_id and marketplace_id now also carry product_id, enabling consistent per-product filtering across the full log pipeline.
• DEBUG logpoints — New structured DEBUG logs for credential injection (fast path and slow path, with credential_path, injected_header_count, plugin_duration_ms) and transaction context parsing.
• Log-safe URL handling — All log output records only the host portion of vendor URLs. sanitizeURL (which kept the path) was replaced by extractTargetHost throughout. The allow-list rejection log gains target_host which was previously absent despite a comment claiming otherwise.
• 499 on client disconnect — context.Canceled from the plugin now writes status 499 (StatusClientClosedRequest) so the access log captures the correct status rather than the default 200.
• Startup visibility — The configured allow-list (hosts and route count) is logged at startup.

---

Before / After log comparison

Successful request

Before (3 lines, from plan):

{"level":"WARN","msg":"forwarding to insecure HTTP target - DEVELOPMENT ONLY","trace_id":"...","target_host":"localhost:9099"}
{"level":"INFO","msg":"upstream response","trace_id":"...","status":200,"content_length":246}
{"level":"INFO","msg":"request completed","trace_id":"...","method":"GET","path":"/proxy","status":200,"latency_ms":9,"vendor_id":"VA-microsoft","client_ip":"","remote_addr":"[::1]:63723"}

After (6 lines at DEBUG):

{"level":"DEBUG","msg":"allow list validation passed","trace_id":"aa3aa905...","target_host":"localhost:9099"}
{"level":"DEBUG","msg":"transaction context parsed","trace_id":"aa3aa905...","vendor_id":"VA-microsoft","marketplace_id":"MP-US","product_id":"","target_host":"localhost:9099"}
{"level":"WARN","msg":"forwarding to insecure HTTP target - DEVELOPMENT ONLY","trace_id":"aa3aa905...","target_host":"localhost:9099"}
{"level":"DEBUG","msg":"credentials injected","trace_id":"aa3aa905...","vendor_id":"VA-microsoft","marketplace_id":"MP-US","target_host":"localhost:9099","credential_path":"fast","injected_header_count":1,"plugin_duration_ms":2}
{"level":"INFO","msg":"upstream response","trace_id":"aa3aa905...","status":200,"content_length":246,"vendor_id":"VA-microsoft","marketplace_id":"MP-US","product_id":"","target_host":"localhost:9099"}
{"level":"INFO","msg":"request completed","trace_id":"aa3aa905...","method":"GET","path":"/proxy","status":200,"latency_ms":4,"vendor_id":"VA-microsoft","marketplace_id":"MP-US","product_id":"","target_host":"localhost:9099","client_ip":"","remote_addr":"[::1]:58186"}

Failing request (unknown marketplace)

Before (3 lines, from plan):

{"level":"WARN","msg":"forwarding to insecure HTTP target - DEVELOPMENT ONLY","trace_id":"...","target_host":"localhost:9099"}
{"level":"ERROR","msg":"plugin error","trace_id":"...","error":"resolving TenantID: no mapping rule matched"}
{"level":"INFO","msg":"request completed","trace_id":"...","method":"GET","path":"/proxy","status":500,"latency_ms":0,"vendor_id":"VA-microsoft","client_ip":"","remote_addr":"[::1]:63740"}

After (5 lines at DEBUG):

{"level":"DEBUG","msg":"allow list validation passed","trace_id":"7397e8ba...","target_host":"localhost:9099"}
{"level":"DEBUG","msg":"transaction context parsed","trace_id":"7397e8ba...","vendor_id":"VA-microsoft","marketplace_id":"MP-APAC","product_id":"","target_host":"localhost:9099"}
{"level":"WARN","msg":"forwarding to insecure HTTP target - DEVELOPMENT ONLY","trace_id":"7397e8ba...","target_host":"localhost:9099"}
{"level":"ERROR","msg":"plugin error","trace_id":"7397e8ba...","vendor_id":"VA-microsoft","marketplace_id":"MP-APAC","product_id":"","target_host":"localhost:9099","error":"resolving TenantID: no mapping rule matched"}
{"level":"INFO","msg":"request completed","trace_id":"7397e8ba...","method":"GET","path":"/proxy","status":500,"latency_ms":0,"vendor_id":"VA-microsoft","marketplace_id":"MP-APAC","product_id":"","target_host":"localhost:9099","client_ip":"","remote_addr":"[::1]:58189"}

Every line is now traceable by trace_id, and the error log immediately tells you it was MP-APAC that had no mapping — no need to correlate with the request completed line. At INFO level only the last 2 lines appear, matching the plan's expected output exactly.

---

Benchmark Comparison: master → feat/improve-core-logging

Apple M1 Pro · Go · n=6 runs · benchstat p<0.05
Only showing benchmarks with meaningful signal — everything else was ~ (no significant change).

internal/proxy — the only package with real changes

Benchmark	master ns/op	branch ns/op	Δ time	Δ B/op	Δ allocs
FullRequestCycle_FastPath	71.12 µs	73.01 µs	+2.67%	+1.80%	+9.91%
FullRequestCycle_SlowPath	68.98 µs	71.05 µs	+3.00%	+1.74%	+9.14%
FullRequestCycle_NoPlugin	67.34 µs	69.57 µs	+3.31%	+1.68%	+8.33%
RequestLoggingMiddleware	1.334 µs	1.908 µs	+43%	+72%	+36%
MiddlewareStack	1.796 µs	2.402 µs	+34%	+36%	+22%
MiddlewareStack_Parallel	3.206 µs	3.543 µs	+10.5%	+5.04%	+11.4%
PanicRecoveryMiddleware	110.1 ns	111.6 ns	+1.32%	~	~

All other packages — no significant change

Package	Result
internal/cache	~ (all ns/op within noise)
internal/context	~ (small apparent improvement, no allocation change)
internal/observability	~
internal/router	~
internal/security	~

Interpretation

The FullRequestCycle numbers (+2.7–3.3%) reflect the new DEBUG logpoints (transaction context parsed, credentials injected) being evaluated per request — even though slog.Debug no-ops when debug level is disabled, the attribute construction still happens. The allocation bump (+8–10%) is the same cause.

The RequestLoggingMiddleware +43% and MiddlewareStack +34% are real and expected: the access log now emits 4 additional slog attributes per request (marketplace_id, product_id, target_host, plus the URL parse). These are the meaningful costs of this branch — ~570 ns and ~329 bytes added to the middleware stack per request, in exchange for a fully contextualized access log.

Raw benchmark files:

• master: bench-master.txt
• feat/improve-core-logging: bench-branch.txt