feat(server): tee access log to a rotated file for on-disk audit trail

Add --access-log <path> (env ZDDC_ACCESS_LOG). When set, every access-
log record is written as a JSON line to the configured file in
addition to the existing slog.Default() stderr output. Empty (default)
keeps the prior behavior — stderr only.

Rotation via gopkg.in/natefinch/lumberjack.v2:
  100 MB per file, 10 backups, 90-day max age, gzip rotated files.

Operator usage (e.g. behind a Caddy/quadlet stack):
  zddc-server --access-log /srv/.zddc.d/logs/access.log ...

Architecture:
  AccessLogMiddleware now takes an optional *slog.Logger. main.go wires
  it via setupAccessAuditLog() which builds a slog.JSONHandler over a
  lumberjack rotator. Stderr emission stays via slog.Default(); the
  audit logger gets the same fields in line-delimited JSON, the format
  every standard log shipper (Vector, Loki, fluentbit, journalbeat)
  parses natively.

Tests cover the audit logger receiving the same email/path/status
fields as the stderr stream.
This commit is contained in:
ZDDC 2026-05-03 23:38:14 -05:00
parent eaecaaee29
commit 8df0defbd2
6 changed files with 107 additions and 9 deletions

View file

@ -22,6 +22,7 @@ import (
"codeberg.org/VARASYS/ZDDC/zddc/internal/zddc" "codeberg.org/VARASYS/ZDDC/zddc/internal/zddc"
"github.com/klauspost/compress/gzhttp" "github.com/klauspost/compress/gzhttp"
"gopkg.in/natefinch/lumberjack.v2"
) )
// version is the binary's own version, injected at build time via // version is the binary's own version, injected at build time via
@ -108,7 +109,8 @@ func main() {
// the context the outer ACL middleware set. // the context the outer ACL middleware set.
// CORSMiddleware — Origin / preflight handling. // CORSMiddleware — Origin / preflight handling.
// dispatch — the actual request handler. // dispatch — the actual request handler.
mux.Handle("/", handler.ACLMiddleware(cfg, handler.AccessLogMiddleware(handler.CORSMiddleware(cfg, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { auditLogger := setupAccessAuditLog(cfg.AccessLog)
mux.Handle("/", handler.ACLMiddleware(cfg, handler.AccessLogMiddleware(auditLogger, handler.CORSMiddleware(cfg, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
dispatch(cfg, idx, logRing, appsServer, w, r) dispatch(cfg, idx, logRing, appsServer, w, r)
}))))) })))))
@ -154,6 +156,43 @@ func main() {
slog.Info("stopped") slog.Info("stopped")
} }
// setupAccessAuditLog constructs a slog.Logger writing JSON lines to a
// size-rotated file at the operator-configured path. Returns nil if no
// path is configured — AccessLogMiddleware then logs only to stderr
// (existing behavior).
//
// Rotation is via lumberjack: 100 MB per file, 10 backups, 90-day max
// age, gzip compression on rotated files. Tuning is fixed (not exposed
// as flags) — these defaults match what an audit-trail use case needs;
// operators wanting stricter retention can wire up logrotate against
// the rotated files themselves.
//
// File-permission posture: lumberjack creates new logs with mode 0600
// (running user only). For multi-user audit access, the operator should
// use group-readable parent directory permissions and either chmod the
// log out-of-band or run a forwarder that has its own read access.
// Parent directory must already exist — this function does NOT mkdir,
// since we'd need to assume too much about umask/owner.
func setupAccessAuditLog(path string) *slog.Logger {
if path == "" {
return nil
}
rotator := &lumberjack.Logger{
Filename: path,
MaxSize: 100, // megabytes per file before rotation
MaxBackups: 10,
MaxAge: 90, // days
Compress: true,
}
// JSON handler — line-delimited JSON is the format every standard
// log shipper (Vector, Loki promtail, fluentbit, journalbeat) parses
// natively, and stays grep-friendly for ad-hoc inspection.
h := slog.NewJSONHandler(rotator, &slog.HandlerOptions{Level: slog.LevelInfo})
slog.Info("access log file enabled",
"path", path, "max_size_mb", 100, "max_backups", 10, "max_age_days", 90)
return slog.New(h)
}
// newGzipWrapper builds the gzip middleware applied to the entire mux. // newGzipWrapper builds the gzip middleware applied to the entire mux.
// MinSize(1024) skips compressing tiny responses where the framing // MinSize(1024) skips compressing tiny responses where the framing
// overhead exceeds the savings (304 Not Modified, error pages, small // overhead exceeds the savings (304 Not Modified, error pages, small

View file

@ -5,6 +5,7 @@ go 1.24
require ( require (
github.com/fsnotify/fsnotify v1.9.0 github.com/fsnotify/fsnotify v1.9.0
github.com/klauspost/compress v1.18.6 github.com/klauspost/compress v1.18.6
gopkg.in/natefinch/lumberjack.v2 v2.2.1
gopkg.in/yaml.v3 v3.0.1 gopkg.in/yaml.v3 v3.0.1
) )

View file

@ -6,5 +6,7 @@ golang.org/x/sys v0.26.0 h1:KHjCJyddX0LoSTb3J+vWpupP9p0oznkqVk/IfjymZbo=
golang.org/x/sys v0.26.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/sys v0.26.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/natefinch/lumberjack.v2 v2.2.1 h1:bBRl1b0OH9s/DuPhuXpNl+VtCaJXFZ5/uEFST95x9zc=
gopkg.in/natefinch/lumberjack.v2 v2.2.1/go.mod h1:YD8tP3GAjkrDg1eZH7EGmyESg/lsYskCTPBJVb9jqSc=
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

View file

@ -23,6 +23,7 @@ type Config struct {
IndexPath string // --index-path / ZDDC_INDEX_PATH — virtual archive prefix (default .archive) IndexPath string // --index-path / ZDDC_INDEX_PATH — virtual archive prefix (default .archive)
EmailHeader string // --email-header / ZDDC_EMAIL_HEADER — auth header name (default X-Auth-Request-Email) EmailHeader string // --email-header / ZDDC_EMAIL_HEADER — auth header name (default X-Auth-Request-Email)
CORSOrigins []string // --cors-origin / ZDDC_CORS_ORIGIN — comma-separated allowlist; default https://zddc.varasys.io; empty disables CORSOrigins []string // --cors-origin / ZDDC_CORS_ORIGIN — comma-separated allowlist; default https://zddc.varasys.io; empty disables
AccessLog string // --access-log / ZDDC_ACCESS_LOG — file path for tee'd JSON access log; empty = stderr only
} }
// ErrHelpRequested is returned by Load when --help is passed; the caller // ErrHelpRequested is returned by Load when --help is passed; the caller
@ -73,6 +74,8 @@ func Load(args []string) (Config, error) {
"Comma-separated CORS allowlist. Empty = CORS disabled. Default: ZDDC_CORS_ORIGIN or https://zddc.varasys.io.") "Comma-separated CORS allowlist. Empty = CORS disabled. Default: ZDDC_CORS_ORIGIN or https://zddc.varasys.io.")
insecureDirectFlag := fs.Bool("insecure-direct", os.Getenv("ZDDC_INSECURE_DIRECT") == "1", insecureDirectFlag := fs.Bool("insecure-direct", os.Getenv("ZDDC_INSECURE_DIRECT") == "1",
"Allow plain HTTP on non-loopback addresses (only safe behind an authenticating proxy).") "Allow plain HTTP on non-loopback addresses (only safe behind an authenticating proxy).")
accessLogFlag := fs.String("access-log", os.Getenv("ZDDC_ACCESS_LOG"),
"Tee structured access logs to this file (JSON, size-rotated). Empty = stderr only.")
helpFlag := fs.Bool("help", false, "Print this help and exit.") helpFlag := fs.Bool("help", false, "Print this help and exit.")
versionFlag := fs.Bool("version", false, "Print version info and exit.") versionFlag := fs.Bool("version", false, "Print version info and exit.")
@ -113,6 +116,7 @@ func Load(args []string) (Config, error) {
IndexPath: *indexPathFlag, IndexPath: *indexPathFlag,
EmailHeader: *emailHeaderFlag, EmailHeader: *emailHeaderFlag,
CORSOrigins: resolveCORS(corsFlagSet, *corsOriginFlag), CORSOrigins: resolveCORS(corsFlagSet, *corsOriginFlag),
AccessLog: *accessLogFlag,
} }
// Default Root to the current working directory. // Default Root to the current working directory.
@ -182,6 +186,7 @@ func Usage(w io.Writer) {
fs.String("email-header", "X-Auth-Request-Email", "HTTP header carrying the authenticated user's email.") fs.String("email-header", "X-Auth-Request-Email", "HTTP header carrying the authenticated user's email.")
fs.String("cors-origin", "", "Comma-separated CORS allowlist. Empty = CORS disabled.") fs.String("cors-origin", "", "Comma-separated CORS allowlist. Empty = CORS disabled.")
fs.Bool("insecure-direct", false, "Allow plain HTTP on non-loopback addresses.") fs.Bool("insecure-direct", false, "Allow plain HTTP on non-loopback addresses.")
fs.String("access-log", "", "Tee structured access logs to this file (JSON, size-rotated). Empty = stderr only.")
fs.Bool("help", false, "Print this help and exit.") fs.Bool("help", false, "Print this help and exit.")
fs.Bool("version", false, "Print version info and exit.") fs.Bool("version", false, "Print version info and exit.")
fs.PrintDefaults() fs.PrintDefaults()

View file

@ -67,8 +67,19 @@ func (rw *responseWriter) Write(b []byte) (int, error) {
return n, err return n, err
} }
// AccessLogMiddleware logs a structured line per HTTP request after the response is written. // AccessLogMiddleware logs a structured line per HTTP request after the
func AccessLogMiddleware(next http.Handler) http.Handler { // response is written.
//
// Always emits to slog.Default() (stderr) so server-lifecycle logs and
// access logs share an output stream by default.
//
// If `auditLogger` is non-nil, the same structured fields are also written
// to it. The intended caller wires up auditLogger with a JSON handler
// pointing at a rotating file (see cmd/zddc-server's setupAccessAuditLog),
// so an operator gets a persisted audit trail on disk in addition to the
// stderr stream — useful when stderr is not journald-captured (e.g.
// container logging where the orchestrator drops stderr after restarts).
func AccessLogMiddleware(auditLogger *slog.Logger, next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
// Capture request start time // Capture request start time
start := time.Now() start := time.Now()
@ -88,8 +99,7 @@ func AccessLogMiddleware(next http.Handler) http.Handler {
email = "anonymous" email = "anonymous"
} }
// Log access args := []any{
slog.Info("access",
"ts", start.Format(time.RFC3339), "ts", start.Format(time.RFC3339),
"email", email, "email", email,
"method", r.Method, "method", r.Method,
@ -97,6 +107,15 @@ func AccessLogMiddleware(next http.Handler) http.Handler {
"status", wrapped.status, "status", wrapped.status,
"bytes", wrapped.bytes, "bytes", wrapped.bytes,
"duration_ms", durationMs, "duration_ms", durationMs,
) }
// Stderr stream (existing behavior).
slog.Info("access", args...)
// Audit file (when configured). Same fields, separate handler so
// the file can be JSON-formatted regardless of stderr's handler.
if auditLogger != nil {
auditLogger.Info("access", args...)
}
}) })
} }

View file

@ -32,7 +32,7 @@ func TestAccessLogReadsEmailFromACLContext(t *testing.T) {
// Correct order: ACL is outer, AccessLog is inner. AccessLog reads // Correct order: ACL is outer, AccessLog is inner. AccessLog reads
// email from the context ACL populated. // email from the context ACL populated.
chain := ACLMiddleware(cfg, AccessLogMiddleware(noop)) chain := ACLMiddleware(cfg, AccessLogMiddleware(nil, noop))
req := httptest.NewRequest(http.MethodGet, "/foo", nil) req := httptest.NewRequest(http.MethodGet, "/foo", nil)
req.Header.Set("X-Auth-Request-Email", "alice@example.com") req.Header.Set("X-Auth-Request-Email", "alice@example.com")
@ -60,7 +60,7 @@ func TestAccessLogAnonymousWhenNoEmail(t *testing.T) {
w.WriteHeader(http.StatusOK) w.WriteHeader(http.StatusOK)
}) })
chain := ACLMiddleware(cfg, AccessLogMiddleware(noop)) chain := ACLMiddleware(cfg, AccessLogMiddleware(nil, noop))
req := httptest.NewRequest(http.MethodGet, "/foo", nil) req := httptest.NewRequest(http.MethodGet, "/foo", nil)
// Note: no X-Auth-Request-Email header set. // Note: no X-Auth-Request-Email header set.
@ -90,7 +90,7 @@ func TestAccessLogOuterDoesNotSeeInnerContext(t *testing.T) {
}) })
// Inverted order — the ORIGINAL buggy chain. // Inverted order — the ORIGINAL buggy chain.
chain := AccessLogMiddleware(ACLMiddleware(cfg, noop)) chain := AccessLogMiddleware(nil, ACLMiddleware(cfg, noop))
req := httptest.NewRequest(http.MethodGet, "/foo", nil) req := httptest.NewRequest(http.MethodGet, "/foo", nil)
req.Header.Set("X-Auth-Request-Email", "alice@example.com") req.Header.Set("X-Auth-Request-Email", "alice@example.com")
@ -104,3 +104,35 @@ func TestAccessLogOuterDoesNotSeeInnerContext(t *testing.T) {
t.Errorf("expected the inverted (buggy) chain to fall back to email=anonymous, got: %s", got) t.Errorf("expected the inverted (buggy) chain to fall back to email=anonymous, got: %s", got)
} }
} }
// TestAccessLogMiddleware_AuditLoggerReceivesSameFields verifies the
// optional audit-logger argument: when non-nil, it gets a parallel copy
// of every access record. Used by main.go to tee access logs to a
// rotating file in addition to stderr.
func TestAccessLogMiddleware_AuditLoggerReceivesSameFields(t *testing.T) {
var auditBuf bytes.Buffer
auditLogger := slog.New(slog.NewJSONHandler(&auditBuf, &slog.HandlerOptions{Level: slog.LevelInfo}))
noop := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
w.WriteHeader(http.StatusTeapot)
_, _ = w.Write([]byte("hi"))
})
cfg := config.Config{EmailHeader: "X-Auth-Request-Email"}
chain := ACLMiddleware(cfg, AccessLogMiddleware(auditLogger, noop))
req := httptest.NewRequest(http.MethodGet, "/some/path", nil)
req.Header.Set("X-Auth-Request-Email", "bob@example.com")
chain.ServeHTTP(httptest.NewRecorder(), req)
out := auditBuf.String()
if !strings.Contains(out, `"email":"bob@example.com"`) {
t.Errorf("audit log missing email field; got: %s", out)
}
if !strings.Contains(out, `"path":"/some/path"`) {
t.Errorf("audit log missing path; got: %s", out)
}
if !strings.Contains(out, `"status":418`) {
t.Errorf("audit log missing status code; got: %s", out)
}
}