From f140398d475d24338e3dd406362f19c71c445c75 Mon Sep 17 00:00:00 2001 From: robertjamesprior <83608739+robertjamesprior@users.noreply.github.com> Date: Mon, 14 Sep 2026 21:54:14 +0000 Subject: [PATCH] Record request fields on forwarded Caddy access logs caddyLogEntry had no fields for request, status, size or duration, so json.Unmarshal discarded them and every access entry was forwarded as an identical "caddy: handled request" with no status code, path or client. Caddy fronts the per-session endpoints, so that surface had no usable access logging at all. Headers are deliberately not parsed and only the URI path is recorded: headers carry Cookie and Authorization, and per-session URLs carry credentials in query parameters. Co-Authored-By: Claude Opus 5 --- lib/ingress/logs.go | 40 +++++++++++++++++ lib/ingress/logs_test.go | 93 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 133 insertions(+) create mode 100644 lib/ingress/logs_test.go diff --git a/lib/ingress/logs.go b/lib/ingress/logs.go index f085b039a..923d55508 100644 --- a/lib/ingress/logs.go +++ b/lib/ingress/logs.go @@ -84,6 +84,33 @@ type caddyLogEntry struct { Error string `json:"error,omitempty"` Module string `json:"module,omitempty"` Adapter string `json:"adapter,omitempty"` + + // Present on http.log.access entries only. + Request *caddyLogRequest `json:"request"` + Status int `json:"status"` + Size int64 `json:"size"` + BytesRead int64 `json:"bytes_read"` + Duration float64 `json:"duration"` +} + +// caddyLogRequest is the request block of an access-log entry. Headers are +// deliberately not parsed: they carry cookies and authorization tokens. +type caddyLogRequest struct { + Method string `json:"method"` + Host string `json:"host"` + URI string `json:"uri"` + Proto string `json:"proto"` + ClientIP string `json:"client_ip"` +} + +// requestPath drops the query string from an access-log URI. Per-session +// endpoints carry credentials in query parameters, so only the path is +// recorded. +func requestPath(uri string) string { + if i := strings.IndexByte(uri, '?'); i >= 0 { + return uri[:i] + } + return uri } // forwardLogLine parses a JSON log line and forwards to OTEL logger. @@ -121,6 +148,19 @@ func (f *CaddyLogForwarder) forwardLogLine(ctx context.Context, line string) { if entry.Error != "" { attrs = append(attrs, "error", entry.Error) } + if entry.Request != nil { + attrs = append(attrs, + "http_method", entry.Request.Method, + "http_host", entry.Request.Host, + "http_path", requestPath(entry.Request.URI), + "http_proto", entry.Request.Proto, + "client_ip", entry.Request.ClientIP, + "http_status", entry.Status, + "duration_seconds", entry.Duration, + "bytes_written", entry.Size, + "bytes_read", entry.BytesRead, + ) + } // Forward with appropriate level msg := "caddy: " + entry.Msg diff --git a/lib/ingress/logs_test.go b/lib/ingress/logs_test.go new file mode 100644 index 000000000..4ef8bb3a4 --- /dev/null +++ b/lib/ingress/logs_test.go @@ -0,0 +1,93 @@ +package ingress + +import ( + "context" + "log/slog" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// captureHandler records the attributes of every log record it handles. +type captureHandler struct { + records []slog.Record +} + +func (h *captureHandler) Enabled(context.Context, slog.Level) bool { return true } + +func (h *captureHandler) Handle(_ context.Context, r slog.Record) error { + h.records = append(h.records, r) + return nil +} + +func (h *captureHandler) WithAttrs([]slog.Attr) slog.Handler { return h } + +func (h *captureHandler) WithGroup(string) slog.Handler { return h } + +func (h *captureHandler) attrs(t *testing.T) map[string]any { + t.Helper() + require.Len(t, h.records, 1) + attrs := map[string]any{} + h.records[0].Attrs(func(a slog.Attr) bool { + attrs[a.Key] = a.Value.Any() + return true + }) + return attrs +} + +func newCaptureForwarder() (*CaddyLogForwarder, *captureHandler) { + h := &captureHandler{} + return &CaddyLogForwarder{logger: slog.New(h)}, h +} + +func TestForwardLogLineAccessEntry(t *testing.T) { + f, h := newCaptureForwarder() + + f.forwardLogLine(context.Background(), `{"level":"info","ts":1788907156.1030767,"logger":"http.log.access","msg":"handled request","request":{"remote_ip":"157.245.71.106","client_ip":"157.245.71.106","proto":"HTTP/1.1","method":"GET","host":"abc123.prod-iad-hypeman-4.kernel.sh","uri":"/json/version","headers":{"Cookie":["session=secret"]}},"bytes_read":12,"duration":0.00001989,"size":34,"status":502}`) + + attrs := h.attrs(t) + assert.Equal(t, "GET", attrs["http_method"]) + assert.Equal(t, "abc123.prod-iad-hypeman-4.kernel.sh", attrs["http_host"]) + assert.Equal(t, "/json/version", attrs["http_path"]) + assert.Equal(t, "HTTP/1.1", attrs["http_proto"]) + assert.Equal(t, "157.245.71.106", attrs["client_ip"]) + assert.Equal(t, int64(502), attrs["http_status"]) + assert.Equal(t, int64(34), attrs["bytes_written"]) + assert.Equal(t, int64(12), attrs["bytes_read"]) + assert.InDelta(t, 0.00001989, attrs["duration_seconds"], 1e-12) +} + +func TestForwardLogLineDropsQueryAndHeaders(t *testing.T) { + f, h := newCaptureForwarder() + + f.forwardLogLine(context.Background(), `{"level":"info","ts":1788907156.1,"logger":"http.log.access","msg":"handled request","request":{"method":"GET","host":"abc.kernel.sh","uri":"/live?token=super-secret","headers":{"Authorization":["Bearer super-secret"]}},"status":200}`) + + attrs := h.attrs(t) + assert.Equal(t, "/live", attrs["http_path"]) + for k, v := range attrs { + str, ok := v.(string) + if !ok { + continue + } + assert.NotContains(t, str, "super-secret", "attribute %q leaked a credential", k) + } +} + +func TestForwardLogLineNonAccessEntry(t *testing.T) { + f, h := newCaptureForwarder() + + f.forwardLogLine(context.Background(), `{"level":"info","ts":1788907156.1,"logger":"admin","msg":"config loaded"}`) + + attrs := h.attrs(t) + assert.NotContains(t, attrs, "http_status") + assert.NotContains(t, attrs, "http_path") + assert.Equal(t, "admin", attrs["caddy_logger"]) +} + +func TestRequestPath(t *testing.T) { + assert.Equal(t, "/json/version", requestPath("/json/version")) + assert.Equal(t, "/live", requestPath("/live?token=abc")) + assert.Equal(t, "", requestPath("?token=abc")) + assert.Equal(t, "", requestPath("")) +}