feat(log): json/logfmt/text output with request-scoped labels

README.md

@@ -107,8 +107,9 @@ your own site a second later. Startup warnings are worth reading: an
 auto-generated HMAC key means passes die on restart and no second instance can
 verify them, which is fine for a first run and wrong in production.
 
-`ANTEROOM_LISTEN`, `ANTEROOM_UPSTREAM`, `ANTEROOM_PAGES`, and `ANTEROOM_HMAC_KEY`
-override the file, for containers and secret managers.
+`ANTEROOM_LISTEN`, `ANTEROOM_UPSTREAM`, `ANTEROOM_PAGES`, `ANTEROOM_HMAC_KEY`,
+`ANTEROOM_LOG_LEVEL`, and `ANTEROOM_LOG_FORMAT` override the file, for containers
+and secret managers.
 
 Run with `-v` to log one line per request naming which rung of the ladder answered
 it (`pass-pow`, `wait-page`, `refusal`, `bypass-path`, …) with the status, size,

anteroom.example.toml

@@ -2,7 +2,8 @@
 #
 # This file is the public configuration contract.
 # Only `upstream` is required. Environment variables override the file:
-# ANTEROOM_LISTEN, ANTEROOM_ADMIN_LISTEN, ANTEROOM_UPSTREAM, ANTEROOM_HMAC_KEY, ...
+# ANTEROOM_LISTEN, ANTEROOM_ADMIN_LISTEN, ANTEROOM_UPSTREAM, ANTEROOM_HMAC_KEY,
+# ANTEROOM_LOG_LEVEL, ANTEROOM_LOG_FORMAT, ...
 
 listen   = "127.0.0.1:8080"       # bind address. Loopback by default: the documented
                                   # topology puts a TLS terminator in front, and a gate
@@ -88,6 +89,20 @@ trusted_proxies = []              # CIDRs whose X-Forwarded-For is believed.
 #kid = "k1"
 #key = "base64..."
 
+# ---------------------------------------------------------------------------
+# Logging. Default is text at info — a terminal. json is the usual choice
+# under Kubernetes; logfmt is the usual choice for Grafana Alloy / Promtail.
+# `anteroom -v` still forces debug (one hit line per request) regardless of
+# level. Request-scoped fields (request_id, and trace_id/span_id when the
+# inbound request carried a W3C traceparent) attach automatically; they are
+# not configured here. Static labels go on every line.
+# ---------------------------------------------------------------------------
+# [log]
+# level  = "info"    # debug | info | warn | error
+# format = "text"    # json | logfmt | text
+# [log.labels]
+# service = "anteroom"
+
 # ---------------------------------------------------------------------------
 # Challenge-activity log (optional). Omit this whole section to keep the gate
 # fully free of per-visitor state. When set, the admin listener (admin_listen
@@ -269,7 +284,9 @@ allow_hosted_fetchers = true             # Claude-User, ChatGPT-User, Google-Age
 # gate exposes counters for YOUR scraper and phones home to nobody.
 #
 # Run with -v to log one line per request naming which rung of the ladder answered
-# it; useful when a request is being walled and you want to know why.
+# it; useful when a request is being walled and you want to know why. Each line
+# carries request_id (honoring inbound X-Request-ID, or generated) so it joins
+# the upstream's logs. format = "json" under [log] if a collector will parse it.
 #
 # Before going live, read docs/operating.md — it lists what Anteroom breaks
 # without bypass rules (webhooks, OAuth callbacks, API clients, feeds, link

charts/kyverno-policies/values.yaml

@@ -163,6 +163,13 @@ gateConfig: |
   renew_difficulty = 6  # renewals are cheap by design (mobile battery)
   inject = true         # add the renewal script to proxied HTML
 
+  # Logging. Default is text at info. json is the usual choice in-cluster.
+  # [log]
+  # level  = "info"     # debug | info | warn | error. -v still forces debug.
+  # format = "json"     # json | logfmt | text
+  # [log.labels]
+  # cluster = "prod"
+
   # Trap 1 in docs/docker.md, and it applies with full force to
   # Kubernetes: WebCrypto and service workers require a secure
   # context — HTTPS or localhost. Reaching a NodePort at

cmd/anteroom/main.go

@@ -10,7 +10,6 @@ import (
 	"flag"
 	"fmt"
 	"io"
-	"log/slog"
 	"net"
 	"net/http"
 	"os"
@@ -22,6 +21,7 @@ import (
 	"github.com/radiustechsystems/anteroom/internal/admin"
 	"github.com/radiustechsystems/anteroom/internal/config"
 	"github.com/radiustechsystems/anteroom/internal/gate"
+	"github.com/radiustechsystems/anteroom/internal/logging"
 )
 
 // bindError supplies the context the standard library's message lacks: a
@@ -59,11 +59,6 @@ func run() error {
 	check := flag.Bool("healthcheck", false, "probe the local gate's health endpoint and exit 0 (healthy) or 1; for container HEALTHCHECK, which has no shell to run curl in")
 	flag.Parse()
 
-	level := slog.LevelInfo
-	if *verbose {
-		level = slog.LevelDebug
-	}
-	lg := slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{Level: level}))
 	cfg, err := config.Load(*cfgPath)
 	if err != nil {
 		return err
@@ -73,6 +68,7 @@ func run() error {
 		return healthcheck(cfg.Listen)
 	}
 
+	lg := logging.New(os.Stderr, cfg.Log, *verbose)
 	g, err := gate.New(cfg, lg)
 	if err != nil {
 		return err

docs/docker.md

@@ -113,7 +113,7 @@ which commit it is.
 
 ## The container contract
 
-**Environment variables.** Only these four exist. Everything else is a config
+**Environment variables.** Only these exist. Everything else is a config
 file setting, deliberately — the surface an operator can change without review
 is kept small.
 
@@ -123,6 +123,8 @@ is kept small.
 | `ANTEROOM_LISTEN` | bind address; defaults to `:8080` |
 | `ANTEROOM_PAGES` | directory holding `header.html` and `footer.html` |
 | `ANTEROOM_HMAC_KEY` | the signing key; registers as `kid = "env"` |
+| `ANTEROOM_LOG_LEVEL` | `debug`, `info`, `warn`, or `error`; `-v` still forces debug |
+| `ANTEROOM_LOG_FORMAT` | `json`, `logfmt`, or `text` (the default) |
 
 **Ports.** The gate binds `:8080` as a non-root user. Publish it as `-p 80:8080`
 and the daemon owns the privileged half — no capability, no root, nothing to

docs/operating.md

@@ -470,7 +470,7 @@ answered it — `own-endpoint`, `bypass-path`, `bypass-ip`, `bypass-crawler`,
 duration:
 
 ```
-level=DEBUG msg=hit method=GET path=/index.html decision=pass-pow status=200 bytes=142 dur=1.2ms ip=203.0.113.9 ua=Mozilla/5.0…
+level=DEBUG msg=hit method=GET path=/index.html decision=pass-pow status=200 bytes=142 dur=1.2ms ip=203.0.113.9 ua=Mozilla/5.0… request_id=…
 ```
 
 This is the fastest way to answer "why was this request walled?", which is
@@ -480,6 +480,29 @@ ignore its logs. Note the line includes the client IP and user agent, so it is
 request-level data — appropriate for debugging, not for leaving on in production
 without deciding that is what you want.
 
+Every request also carries a `request_id` (honoring inbound `X-Request-ID` or
+`X-Correlation-ID`, otherwise generated) and, when the client sent a W3C
+`traceparent`, `trace_id` and `span_id`. The same `X-Request-ID` is forwarded
+upstream so the application's logs join. The gate does not mint spans it never
+exports.
+
+Log encoding is configured under `[log]`. The default is `text` at `info` — a
+terminal. Collectors want `json`; Grafana Alloy / Promtail want `logfmt`.
+`anteroom -v` still forces debug regardless of `log.level`. Static labels
+(`[log.labels]`) land on every line; request-scoped fields attach through
+context and do not need repeating at each call site.
+
+```toml
+[log]
+level  = "info"     # debug | info | warn | error
+format = "json"     # json | logfmt | text
+[log.labels]
+service = "anteroom"
+```
+
+`ANTEROOM_LOG_LEVEL` and `ANTEROOM_LOG_FORMAT` override the file, the same way
+`ANTEROOM_LISTEN` does.
+
 ## Monitoring
 
 Set `admin_listen` to open an operator port alongside the gate:

internal/config/config.go

@@ -92,13 +92,31 @@ type Config struct {
 	Activity             *Activity `toml:"activity"`
 	Bypass               Bypass    `toml:"bypass"`
 	Triage               Triage    `toml:"triage"`
+	Log                  Log       `toml:"log"`
 
 	// KeyAutoGenerated is set when no hmac_keys were configured and one was
 	// generated for this process. Fleets must not rely on it: every restart
 	// invalidates all passes, and no other instance can verify them.
 	KeyAutoGenerated bool `toml:"-"`
 }
 
+// Log is the process logger. Format is a Handler choice — every call site
+// already emits slog key/value attrs — so json, logfmt, and text are encodings
+// of the same records, not three logging APIs.
+type Log struct {
+	// Level is the floor: debug, info, warn, or error. Default info. `anteroom
+	// -v` still forces debug, so per-request hit lines stay an explicit opt-in
+	// even when the file says info.
+	Level string `toml:"level"`
+	// Format is json, logfmt, or text (the default). json for collectors,
+	// logfmt for Grafana/Promtail, text for a terminal.
+	Format string `toml:"format"`
+	// Labels are static key/value pairs on every line (service, cluster, replica).
+	// Request-scoped fields (request_id, trace_id, span_id) are not configured
+	// here: they come from the request and attach through context.
+	Labels map[string]string `toml:"labels"`
+}
+
 type HMACKey struct {
 	Kid string `toml:"kid"`
 	Key string `toml:"key"` // base64 (std or url, padded or not)
@@ -283,6 +301,10 @@ func defaults() Config {
 		Difficulty:      14,
 		RenewDifficulty: 6,
 		Inject:          true,
+		Log: Log{
+			Level:  "info",
+			Format: "text",
+		},
 		Triage: Triage{
 			JSONAccept: true,
 			// Verified vendor-hosted user fetchers cannot complete PoW or x402,
@@ -344,6 +366,12 @@ func applyEnv(cfg *Config) {
 	if v := os.Getenv("ANTEROOM_HMAC_KEY"); v != "" {
 		cfg.HMACKeys = []HMACKey{{Kid: "env", Key: v}}
 	}
+	if v := os.Getenv("ANTEROOM_LOG_LEVEL"); v != "" {
+		cfg.Log.Level = v
+	}
+	if v := os.Getenv("ANTEROOM_LOG_FORMAT"); v != "" {
+		cfg.Log.Format = v
+	}
 }
 
 func (c *Config) validate() error {
@@ -438,9 +466,51 @@ func (c *Config) validate() error {
 			return err
 		}
 	}
+	if err := c.Log.validate(); err != nil {
+		return err
+	}
 	return nil
 }
 
+func (l Log) validate() error {
+	switch strings.ToLower(strings.TrimSpace(l.Level)) {
+	case "debug", "info", "warn", "warning", "error":
+	default:
+		return fmt.Errorf("config: log.level %q is not debug, info, warn, or error", l.Level)
+	}
+	switch strings.ToLower(strings.TrimSpace(l.Format)) {
+	case "json", "logfmt", "text":
+	default:
+		return fmt.Errorf("config: log.format %q is not json, logfmt, or text — json for collectors, logfmt for Grafana, text for a terminal", l.Format)
+	}
+	reserved := map[string]bool{"time": true, "ts": true, "level": true, "msg": true}
+	for k := range l.Labels {
+		if reserved[k] {
+			return fmt.Errorf("config: log.labels key %q is reserved (time, ts, level, msg)", k)
+		}
+		if !validLabelKey(k) {
+			return fmt.Errorf("config: log.labels key %q must start with a letter or underscore, then letters, digits, or underscores", k)
+		}
+	}
+	return nil
+}
+
+func validLabelKey(k string) bool {
+	if k == "" {
+		return false
+	}
+	for i := 0; i < len(k); i++ {
+		c := k[i]
+		switch {
+		case c >= 'a' && c <= 'z', c >= 'A' && c <= 'Z', c == '_':
+		case i > 0 && c >= '0' && c <= '9':
+		default:
+			return false
+		}
+	}
+	return true
+}
+
 // checkFacilitatorURL validates a facilitator URL under key (a config path for
 // error messages). Empty is the caller's concern — for the global key it is an
 // error, for a rail it means "inherit".

internal/config/config_test.go

@@ -51,6 +51,9 @@ func TestLoadMinimal(t *testing.T) {
 	if !cfg.Inject || !cfg.Triage.JSONAccept || !cfg.Triage.AllowHostedFetchers {
 		t.Error("inject, json_accept, and allow_hosted_fetchers should default true")
 	}
+	if cfg.Log.Level != "info" || cfg.Log.Format != "text" {
+		t.Errorf("log defaults: %+v", cfg.Log)
+	}
 	// No admin listener unless asked for: it is unauthenticated, so silently
 	// opening a port the operator never configured would be a surprise surface.
 	if cfg.AdminListen != "" {
@@ -375,6 +378,10 @@ price = "$0.01"
 		{"activity ttl too long", minimal + "[activity]\nttl = \"48h\"\n", nil, "activity.ttl"},
 		{"activity max_ips out of range", minimal + "[activity]\nmax_ips = 5000000\n", nil, "activity.max_ips"},
 		{"activity unknown key", minimal + "[activity]\nttls = \"10m\"\n", nil, "unknown key"},
+		{"bad log level", minimal + "[log]\nlevel = \"verbose\"\n", nil, "log.level"},
+		{"bad log format", minimal + "[log]\nformat = \"yaml\"\n", nil, "log.format"},
+		{"reserved log label", minimal + "[log.labels]\nmsg = \"nope\"\n", nil, "reserved"},
+		{"bad log label key", minimal + "[log.labels]\n\"not a key\" = \"x\"\n", nil, "log.labels"},
 	} {
 		t.Run(tc.name, func(t *testing.T) {
 			_, err := Load(write(t, tc.body))
@@ -425,6 +432,8 @@ func TestEnvOverrides(t *testing.T) {
 	t.Setenv("ANTEROOM_ADMIN_LISTEN", "127.0.0.1:9998")
 	t.Setenv("ANTEROOM_UPSTREAM", "127.0.0.1:4000")
 	t.Setenv("ANTEROOM_HMAC_KEY", "MDEyMzQ1Njc4OWFiY2RlZjAxMjM0NTY3ODlhYmNkZWY=")
+	t.Setenv("ANTEROOM_LOG_LEVEL", "debug")
+	t.Setenv("ANTEROOM_LOG_FORMAT", "json")
 	cfg, err := Load(write(t, minimal))
 	if err != nil {
 		t.Fatalf("Load: %v", err)
@@ -438,6 +447,29 @@ func TestEnvOverrides(t *testing.T) {
 	if cfg.KeyAutoGenerated || cfg.HMACKeys[0].Kid != "env" {
 		t.Errorf("env key not used: %+v", cfg.HMACKeys)
 	}
+	if cfg.Log.Level != "debug" || cfg.Log.Format != "json" {
+		t.Errorf("log env overrides not applied: %+v", cfg.Log)
+	}
+}
+
+func TestLogSection(t *testing.T) {
+	cfg, err := Load(write(t, minimal+`
+[log]
+level = "warn"
+format = "json"
+[log.labels]
+service = "anteroom"
+cluster = "prod"
+`))
+	if err != nil {
+		t.Fatalf("Load: %v", err)
+	}
+	if cfg.Log.Level != "warn" || cfg.Log.Format != "json" {
+		t.Errorf("log section: %+v", cfg.Log)
+	}
+	if cfg.Log.Labels["service"] != "anteroom" || cfg.Log.Labels["cluster"] != "prod" {
+		t.Errorf("log.labels: %v", cfg.Log.Labels)
+	}
 }
 
 func TestParsePrice(t *testing.T) {

internal/gate/endpoints.go

@@ -151,7 +151,7 @@ func (g *Gate) serveChallenge(w http.ResponseWriter, r *http.Request) {
 	}
 	c, issuedAt, err := g.issuer.Issue(now, requestAudience(r), profile)
 	if err != nil {
-		g.lg.Error("issuing challenge", "err", err)
+		g.lg.ErrorContext(r.Context(), "issuing challenge", "err", err)
 		http.Error(w, "internal error", http.StatusInternalServerError)
 		return
 	}
@@ -264,7 +264,7 @@ func (g *Gate) serveAnswer(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 	if err := g.setPassCookie(w, r, token.Pass{Kind: token.KindPoW, Scope: token.ScopeAll}, exp, rootAt); err != nil {
-		g.lg.Error("minting pass", "err", err)
+		g.lg.ErrorContext(r.Context(), "minting pass", "err", err)
 		g.noteAnswer("error", r)
 		w.WriteHeader(http.StatusInternalServerError)
 		json.NewEncoder(w).Encode(answerResponse{Error: "internal error"})

internal/gate/gate.go

@@ -312,7 +312,7 @@ func newProxy(u *url.URL, socket string, m *bypass.Matcher, lg *slog.Logger, ups
 		FlushInterval: -1,
 		ErrorHandler: func(w http.ResponseWriter, r *http.Request, err error) {
 			upstreamErr.Inc()
-			lg.Error("upstream unreachable", "err", err, "path", r.URL.Path)
+			lg.ErrorContext(r.Context(), "upstream unreachable", "err", err, "path", r.URL.Path)
 			http.Error(w, "upstream unreachable", http.StatusBadGateway)
 		},
 	}
@@ -390,7 +390,7 @@ func (g *Gate) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	if ua := request.facts.userAgent; ua != "" {
 		attrs = append(attrs, "ua", ua)
 	}
-	g.lg.Debug("hit", attrs...)
+	g.lg.DebugContext(request.Context(), "hit", attrs...)
 }
 
 // serve is the ladder proper. It returns the name of the rung that answered, for
@@ -571,11 +571,11 @@ func (g *Gate) forward(w http.ResponseWriter, r *http.Request) {
 // noteInjectionSkipped logs every skipped injection at debug level and warns
 // once per reason, avoiding per-request warning noise from persistent policies.
 func (g *Gate) noteInjectionSkipped(r *http.Request, reason string) {
-	g.lg.Debug("renewal script not injected", "reason", reason, "path", r.URL.Path)
+	g.lg.DebugContext(r.Context(), "renewal script not injected", "reason", reason, "path", r.URL.Path)
 	if _, seen := g.skipReported.LoadOrStore(reason, struct{}{}); seen {
 		return
 	}
-	g.lg.Warn("renewal script not injected — visitors reading these pages will lapse and be re-challenged",
+	g.lg.WarnContext(r.Context(), "renewal script not injected — visitors reading these pages will lapse and be re-challenged",
 		"reason", reason,
 		"example_path", r.URL.Path,
 		"consequence", "the pass is not renewed from this response, so the visitor is walled again when it expires",