diff --git a/gateway/configs/config-template.toml b/gateway/configs/config-template.toml index 2596104c0c..bbc50c0261 100644 --- a/gateway/configs/config-template.toml +++ b/gateway/configs/config-template.toml @@ -455,15 +455,46 @@ timer_wakeup_seconds = 3 # ============================================================================= # Writes collected events (rich API/application/AI/latency metadata, plus # request/response headers and — when the collector's request_body/response_body -# is enabled — payloads) to stdout as a JSON line. Useful for log-scraping pipelines such as -# Fluent Bit/Loki/ELK; no external SaaS needed. +# is enabled — payloads) as one JSON line per request, to the sinks named in +# `outputs`. # -# No policy required: enabling this section emits one stdout line for every -# request to every API — including requests an auth policy denied -# (short-circuited), which is otherwise invisible to any logging done from -# inside the policy chain. Honors the shared collector.ignore_path_prefixes. +# No policy required: enabling this section emits one line for every request to +# every API — including requests an auth policy denied (short-circuited), which +# is otherwise invisible to any logging done from inside the policy chain. +# Honors the shared collector.ignore_path_prefixes. [traffic_logging] enabled = false + +# Sinks each line is written to. Any combination of "stdout", "file" and "http"; +# order is irrelevant and duplicates are rejected. An unknown name is a startup +# error, not a silent no-op. Sinks are additive — ["file", "http"] writes both. +# +# stdout the historical default, and still the default. Lines go to the +# container log, and therefore to the node's /var/log/pods files: any +# node-level collector already on the host picks them up with no +# further configuration, and anyone with `kubectl logs` can read them. +# file appends to a rotating file (see [traffic_logging.file]). Keeps +# payloads out of the container log and out of every node-level +# collector, at the cost of a writable volume. +# http batches lines and POSTs them to an endpoint you name (see +# [traffic_logging.http]). Nothing is written to disk and no +# co-located collector — sidecar or DaemonSet — is required. +# +# This choice matters most when the collector's body capture is on: the traffic +# log is the one output that deliberately carries request/response payloads, so +# `outputs` decides where that PII comes to rest. +# +# Sink construction fails closed. A file that cannot be opened or an endpoint +# that cannot be built fails startup — no sink silently degrades to stdout, +# because that would put payloads back in the container log the operator +# selected `file`/`http` to keep them out of. At runtime a delivery failure +# drops the line and counts it (policy_engine_traffic_log_dropped_total); it +# never blocks request processing and never falls back to another sink. +outputs = ["stdout"] + +# Bounds the flush of buffering sinks on SIGTERM. Only the "http" sink buffers; +# "stdout" and "file" write straight to their fd and have nothing to flush. +shutdown_timeout = "5s" # Header names (case-insensitive) whose values are redacted as "****" in the # logged requestHeaders/responseHeaders. masked_headers = ["authorization", "x-api-key", "x-jwt-assertion"] @@ -496,6 +527,187 @@ exclude_fields = [] # instead of one flattened property per claim — reach into it to drop just one: # exclude_fields = ["properties.claims.internal_debug"] +# ----------------------------------------------------------------------------- +# "file" sink — read only when outputs contains "file". +# ----------------------------------------------------------------------------- +[traffic_logging.file] +# SINGLE WRITER ONLY. This must be a per-pod volume (emptyDir, or a PVC bound to +# exactly one replica). A shared RWX volume, hostPath, or NFS mount written by +# more than one gateway pod is NOT supported and will silently lose records — +# there is no error, the lines simply go missing: +# +# * Rotation renames the live file to .1. When one pod rotates, every +# other pod keeps writing to the descriptor it already holds, so their lines +# land in the backup — which the next rotation clobbers. +# * The size counter is per process, seeded at open and advanced by each write. +# With several writers each one undercounts the real file, so the ceiling +# triggers late or never and the file grows past max_size_mb. +# * On NFS an O_APPEND write is not atomic, so concurrent lines can interleave +# and corrupt each other. +# +# Scale-out is fine — give each replica its own volume and let the collector +# (or the http sink) do the merging. +# +# Absolute path of the live log file; a relative path is rejected rather than +# resolved against the working directory. The parent directory is created (0700) +# and the file opened (0600) at startup, so a permissions problem surfaces at +# boot rather than at the first request once payloads are already flowing. Under +# Kubernetes this must sit on a writable volume — the Helm chart provisions and +# mounts one automatically when this sink is selected. +path = "" +# path = "/var/log/wso2/traffic/traffic.log" +# Size at which the live file is rotated: it is renamed to .1 (clobbering +# any previous backup) and reopened, so the worst case on disk is 2 x this value. +# The size counter is seeded from the existing file at open, so the ceiling still +# binds after a restart that appends. +# +# 0 disables rotation and logs a warning. That is permitted for a dedicated, +# sized volume where the volume itself is the bound — but note stdout is bounded +# by the kubelet today, and an unrotated file is bounded by nothing. +max_size_mb = 100 + +# ----------------------------------------------------------------------------- +# "http" sink — read only when outputs contains "http". +# +# Sends newline-delimited JSON, which Splunk HEC's /raw endpoint, Elasticsearch +# and OpenSearch _bulk, Loki, Fluent Bit's http input and the OpenTelemetry +# Collector all accept directly. +# ----------------------------------------------------------------------------- +[traffic_logging.http] +# Absolute URL each batch is POSTed to. Required when this sink is selected. +# Redirects are never followed. +endpoint = "" +# endpoint = "https://splunk.example.com:8088/services/collector/raw?sourcetype=wso2:gateway:traffic" +content_type = "application/x-ndjson" +# Permits a plaintext http:// endpoint. Off by default and intended only for a +# collector on the pod network: these lines carry request/response bodies, so +# plaintext is a real disclosure, not just a hygiene warning. +allow_insecure_transport = false + +# A batch is closed by whichever bound is reached first. +batch_max_events = 100 +batch_max_bytes = 1048576 +flush_interval = "5s" + +# Bounded queue between the ingest path and the sending goroutine. It has to be +# bounded — an unbounded queue in front of a bounded sender is just deferred +# unbounded memory growth, and these events carry bodies, so it grows fast. +# 10000 lines is roughly 100 MiB at a 10 KiB/line worst case: enough to ride out +# a short receiver blip, not enough for a long outage to exhaust the heap. +queue_capacity = 10000 +# What to drop once the queue is full: "drop_new" keeps the older window (suits +# audit), "drop_oldest" keeps recency (suits dashboards). Either way the line is +# counted by policy_engine_traffic_log_dropped_total{reason="queue_full"}. +on_queue_full = "drop_new" + +# Bounds a single POST attempt. +request_timeout = "10s" +# Retry attempts after the initial one, with exponential backoff from +# retry_backoff plus jitter, so replicas recovering from a shared outage do not +# synchronize. Only transport errors, 5xx and 429 are retried — a 4xx means the +# receiver rejected the batch's shape, and retrying would just amplify it. +max_retries = 3 +retry_backoff = "1s" +# Fraction of queue_capacity at which a retrying batch abandons its remaining +# attempts and is counted as dropped_total{reason="backpressure"}. Below it, +# retrying costs nothing; at or above it, every further second of retry is paid +# for in newer events lost to queue_full. +# +# The value is used exactly as written — it is never remapped to a default: +# 0 always abandon retries: one delivery attempt per batch, whatever the +# queue looks like (the same effect as max_retries = 0) +# 0.1 abort once the queue is 10% full — favours draining over saving any +# individual batch +# 0.5 the shipped default: retry freely while the queue is shallow, stop +# once it starts filling +# 1 never abort early where a receiver that accepts but never answers holds +# the sender for the full retry budget +retry_abort_queue_ratio = 0.5 + +# Authentication material sent with every batch. `type` selects the scheme and +# each scheme's fields live in its own sub-table, the same shape [analytics] uses +# for enabled_publishers / [analytics.publishers.]. Only the sub-table +# matching `type` is read; the others are ignored entirely, so leaving a +# populated [.basic] behind while switching to bearer cannot send the wrong +# credential. +# +# type sub-table required header sent +# ---------- -------------------------------- --------------- ----------------------------------------- +# "none" — — (none — the default, and what an +# omitted type resolves to) +# "bearer" [traffic_logging.http.auth.bearer] token Authorization: Bearer +# "basic" [traffic_logging.http.auth.basic] username, Authorization: Basic +# password +# "header" [traffic_logging.http.auth.header] name, value : +# +# Exactly one header is added to the POST — there is no way to combine two +# schemes. A receiver needing more than one header should sit behind a collector +# that adds the rest. +# +# A missing required field for the selected type is a startup error, not a +# silently unauthenticated POST carrying request bodies. The type itself is +# matched case-insensitively and trimmed. +# +# "header" exists for receivers whose scheme is not Bearer: Splunk HEC expects +# "Authorization: Splunk ", which "bearer" cannot express. It also covers +# receivers authenticating on a non-Authorization header entirely. +[traffic_logging.http.auth] +type = "none" + +# Never inline a credential in the sub-tables below. {{ env "VAR" }} and +# {{ file "/path" }} resolve at load time and are never logged; {{ file }} reads +# are restricted to /etc/gateway-runtime and /secrets/gateway-runtime by default. + +# Bearer — e.g. Grafana Loki, Datadog, a generic OTLP/HTTP collector. +[traffic_logging.http.auth.bearer] +token = "" +# token = '{{ env "APIP_GW_TRAFFIC_LOG_HTTP_TOKEN" }}' + +# Basic — e.g. Elasticsearch/OpenSearch _bulk with a native user. +[traffic_logging.http.auth.basic] +username = "" +password = "" +# username = "gateway" +# password = '{{ file "/secrets/gateway-runtime/traffic-log-password" }}' + +# Header — one literal header, sent verbatim. Two common shapes: +# Splunk HEC, which rejects "Bearer" and requires its own scheme: +# name = "Authorization" +# value = 'Splunk {{ file "/secrets/gateway-runtime/hec-token" }}' +# a vendor endpoint authenticating on an API-key header: +# name = "X-API-Key" +# value = '{{ file "/secrets/gateway-runtime/traffic-log-api-key" }}' +[traffic_logging.http.auth.header] +name = "" +value = "" + +# TLS trust and client-certificate material. This is the transport layer and is +# independent of [traffic_logging.http.auth] above: the client certificate proves +# who is connecting, the auth block proves who is making the request. Use either +# alone, or both together — mTLS does not suppress the auth header, and +# type = "none" with a client certificate is a perfectly normal mTLS-only setup. +# +# Ignored entirely when the endpoint is plaintext http:// (see +# allow_insecure_transport), since there is no handshake to configure. +[traffic_logging.http.tls] +# PEM bundle used to verify the receiver's certificate. Empty means the system +# trust store — correct for a public SaaS receiver, usually wrong for an internal +# collector fronted by a private CA. +ca_file = "" +# Client certificate and key for mTLS, in PEM form. Both or neither: setting one +# without the other is a startup error rather than a silently unauthenticated +# connection. Both files are read and parsed at startup, so a wrong path or a +# mismatched pair fails immediately instead of at the first delivery. +# +# cert_file = "/secrets/gateway-runtime/traffic-log-client.crt" +# key_file = "/secrets/gateway-runtime/traffic-log-client.key" +cert_file = "" +key_file = "" +# Disables verification of the receiver's certificate. Off by default; when on, +# startup logs a warning naming the endpoint, because it exposes every logged +# request/response body to anyone able to intercept the connection. +insecure_skip_verify = false + # Optional extra key->value pairs added under a top-level "properties" object. # A value prefixed "$ctx:" is evaluated as a CEL expression against context # built from the collected event; other values are literal strings. diff --git a/gateway/gateway-runtime/policy-engine/cmd/policy-engine/main.go b/gateway/gateway-runtime/policy-engine/cmd/policy-engine/main.go index 9978f14ae8..d89fe8e867 100644 --- a/gateway/gateway-runtime/policy-engine/cmd/policy-engine/main.go +++ b/gateway/gateway-runtime/policy-engine/cmd/policy-engine/main.go @@ -36,6 +36,7 @@ import ( "google.golang.org/grpc" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/admin" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/analytics" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/constants" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/executor" @@ -298,11 +299,12 @@ func main() { // collector is the shared transport that carries collected data to its // consumers (analytics, traffic logging). var alsServer *grpc.Server + var alsAnalytics *analytics.Analytics slog.DebugContext(ctx, "Policy engine ALS server config", "config", cfg.Collector.Server) if cfg.IsCollectorEnabled() { // Start the access log service server slog.Info("Starting the ALS gRPC server...") - alsServer = utils.StartAccessLogServiceServer(cfg) + alsServer, alsAnalytics = utils.StartAccessLogServiceServer(cfg) } // Setup graceful shutdown @@ -353,6 +355,19 @@ func main() { alsServer.GracefulStop() } + // Flush analytics publishers only after the ALS server has stopped, so the + // flush cannot race newly arriving events. Publishers that buffer (the + // traffic-log HTTP sink, Moesif) would otherwise lose their in-flight batch on + // every restart, rolling update and scale-down. + if alsAnalytics != nil { + shutdownCtx, cancel := context.WithTimeout(context.Background(), + cfg.TrafficLogging.EffectiveShutdownTimeout()) + if err := alsAnalytics.Close(shutdownCtx); err != nil { + slog.ErrorContext(ctx, "Error flushing analytics publishers", "error", err) + } + cancel() + } + grpcServer.GracefulStop() // Cleanup Unix socket if used (UDS mode) diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/analytics.go b/gateway/gateway-runtime/policy-engine/internal/analytics/analytics.go index ef600d12db..97ceda48a5 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/analytics.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/analytics.go @@ -18,7 +18,9 @@ package analytics import ( + "context" "encoding/json" + "errors" "fmt" "log/slog" "maps" @@ -128,8 +130,21 @@ func NewAnalytics(cfg *config.Config) *Analytics { // Traffic logging is a standalone consumer, independent of analytics. if cfg.TrafficLogging.Enabled { - publishers = append(publishers, analytics_publisher.NewLog(&cfg.TrafficLogging)) - slog.Info("Traffic logging (stdout) publisher added") + logPublisher, err := analytics_publisher.NewLog(&cfg.TrafficLogging) + if err != nil { + // Fail closed. Continuing without the configured sinks would leave + // traffic logging on stdout or on nothing at all, and the stdout path + // writes request and response bodies into the container log — the + // exact disclosure a file or http sink is configured to prevent. This + // is a startup-time condition verified locally, so refusing to run is + // the correct outcome; config.Validate has already proven every sink + // is constructible, which makes this branch defensive rather than + // reachable in practice. + slog.Error("Failed to initialize traffic-logging sinks; refusing to start", "error", err) + panic(fmt.Sprintf("traffic logging configuration is unusable: %v", err)) + } + publishers = append(publishers, logPublisher) + slog.Info("Traffic logging publisher added", "outputs", cfg.TrafficLogging.Outputs) } if len(publishers) == 0 { @@ -183,6 +198,27 @@ func (c *Analytics) Process(event *v3.HTTPAccessLogEntry) { } +// Close shuts down every publisher that holds resources or buffers events, +// bounded by ctx. Publishers that do not implement Closer are skipped. +// +// Call this only after the ALS server has stopped accepting events, so the flush +// does not race new arrivals. Without it, a buffering publisher (the traffic-log +// HTTP sink, Moesif) loses its in-flight batch on every pod restart, rolling update +// and scale-down. +func (c *Analytics) Close(ctx context.Context) error { + var errs []error + for _, publisher := range c.publishers { + closer, ok := publisher.(analytics_publisher.Closer) + if !ok { + continue + } + if err := closer.Close(ctx); err != nil { + errs = append(errs, err) + } + } + return errors.Join(errs...) +} + // isInternalLoopbackHop identifies the provider-side hop of an LLM proxy loopback call by requiring // both the proxy marker and the unforgeable direct TCP peer; if the peer is unavailable, it fails open, warns once, and allows duplicates. func (c *Analytics) isInternalLoopbackHop(apiType, marker, directRemoteIP, downstreamListener, correlationID string) bool { diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log.go index a2ee69865e..4d2d264996 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log.go @@ -18,12 +18,12 @@ package publishers import ( + "context" "encoding/json" + "errors" "fmt" "log/slog" - "os" "strings" - "sync" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/analytics/dto" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" @@ -32,12 +32,13 @@ import ( // maskedHeaderValue is the placeholder written in place of a masked header value. const maskedHeaderValue = "****" -// Log is an analytics publisher that writes each enriched analytics event to -// stdout as a single JSON line. It is intended for log-scraping pipelines -// (Fluent Bit, Loki, ELK, etc.) and as a lightweight alternative to a SaaS -// analytics backend. The event already carries the rich metadata, headers and -// (when request_body/response_body are enabled) payloads attached by -// the analytics engine, so this publisher only serializes it. +// Log is an analytics publisher that writes each enriched analytics event as a +// single JSON line to one or more sinks. It is intended for log-scraping pipelines +// (Fluent Bit, Loki, ELK, etc.), for direct delivery to a log platform, and as a +// lightweight alternative to a SaaS analytics backend. The event already carries +// the rich metadata, headers and (when request_body/response_body are enabled) +// payloads attached by the analytics engine, so this publisher only serializes it +// and hands the bytes to each configured sink. type Log struct { // maskedHeaders holds lower-cased header names whose values are redacted in // the requestHeaders/responseHeaders properties before logging. @@ -57,14 +58,21 @@ type Log struct { // always returns a usable, possibly-empty evaluator whose resolve() returns // nil when nothing is configured. globalProperties *globalPropertyEvaluator - // mu serializes writes to stdout so concurrent ALS streams do not interleave. - mu sync.Mutex - // out is the destination writer; defaults to os.Stdout (overridable in tests). - out *os.File + // sinks are the destinations each serialized line is written to, built from + // traffic_logging.outputs. Each sink owns its own synchronization, so no lock + // is held here across the fan-out. + sinks []Sink } -// NewLog creates a new stdout traffic-logging publisher. -func NewLog(logCfg *config.TrafficLoggingConfig) *Log { +// NewLog creates a new traffic-logging publisher and its configured sinks. +// +// It returns an error when a sink cannot be built. The caller must treat that as +// fatal: continuing without the sink would leave traffic logging on stdout (or on +// nothing at all), and the stdout path writes request and response bodies into the +// container log, which is precisely what a file or http sink is configured to +// avoid. config.Validate has already proven every configured sink is constructible, +// so an error here means the environment changed during startup. +func NewLog(logCfg *config.TrafficLoggingConfig) (*Log, error) { if logCfg == nil { logCfg = &config.TrafficLoggingConfig{} } @@ -77,13 +85,24 @@ func NewLog(logCfg *config.TrafficLoggingConfig) *Log { } } - return &Log{ + l := &Log{ maskedHeaders: masked, maxPayloadSize: logCfg.MaxPayloadSize, globalDir: buildGlobalDirective(*logCfg), globalProperties: newGlobalPropertyEvaluator(logCfg.Properties, masked), - out: os.Stdout, } + + // Only build sinks when traffic logging is on: Publish is a no-op otherwise, + // so opening a file or starting a sender goroutine would be pure waste — and + // would create the log file on disk for a feature nobody enabled. + if logCfg.Enabled { + sinks, err := newSinks(logCfg) + if err != nil { + return nil, err + } + l.sinks = sinks + } + return l, nil } // buildGlobalDirective converts the traffic-logging config into a @@ -163,12 +182,27 @@ func (l *Log) Publish(event *dto.Event) { l.write(data) } +// write fans the serialized line out to every configured sink. Each sink handles +// its own locking, buffering and failure accounting; a failure in one sink never +// prevents the others from receiving the line, and never propagates to the caller. func (l *Log) write(data []byte) { - l.mu.Lock() - defer l.mu.Unlock() - if _, err := fmt.Fprintln(l.out, string(data)); err != nil { - slog.Error("Failed to write analytics event to stdout", "error", err) + for _, sink := range l.sinks { + sink.Write(data) + } +} + +// Close shuts down every sink, flushing any that buffer. It satisfies Closer, so +// Analytics.Close reaches it during graceful shutdown. Errors from individual sinks +// are joined rather than short-circuited, so one stuck sink cannot prevent the +// others from closing. +func (l *Log) Close(ctx context.Context) error { + var errs []error + for _, sink := range l.sinks { + if err := sink.Close(ctx); err != nil { + errs = append(errs, fmt.Errorf("closing %s sink: %w", sink.Name(), err)) + } } + return errors.Join(errs...) } // parseHeadersFromString converts the JSON-encoded header value stored in diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log_test.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log_test.go index 21d28d54a2..ff4d1ce49c 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log_test.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/log_test.go @@ -20,6 +20,7 @@ package publishers import ( "encoding/json" "fmt" + "io" "os" "path/filepath" "strings" @@ -30,8 +31,28 @@ import ( "github.com/stretchr/testify/require" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/analytics/dto" "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/metrics" ) +// TestMain initializes the metrics registry before any test runs. The sinks record +// counters on every write, and the metric variables are nil until Init() is called, +// so without this the first Write would panic on a nil interface. +func TestMain(m *testing.M) { + // Enabled must be set BEFORE Init: Init is a sync.Once, and with Enabled + // false it builds an empty registry and registers nothing, so any test that + // inspects a metric would silently see no series at all. + metrics.Enabled = true + metrics.Init() + os.Exit(m.Run()) +} + +// useWriterSink redirects a Log publisher's output to w, replacing whatever sinks +// its config produced. Tests use this to capture the emitted bytes instead of +// writing to the process's real stdout. +func useWriterSink(l *Log, w io.Writer) { + l.sinks = []Sink{newWriterSink(w, "test", nil)} +} + // newLogToFile builds a Log publisher that writes to a temp file, returning the // publisher and a function that reads back what was written. func newLogToFile(t *testing.T, cfg *config.TrafficLoggingConfig) (*Log, func() string) { @@ -41,8 +62,9 @@ func newLogToFile(t *testing.T, cfg *config.TrafficLoggingConfig) (*Log, func() require.NoError(t, err) t.Cleanup(func() { _ = f.Close() }) - l := NewLog(cfg) - l.out = f + l, err := NewLog(cfg) + require.NoError(t, err) + useWriterSink(l, f) return l, func() string { require.NoError(t, f.Sync()) data, err := os.ReadFile(path) @@ -83,7 +105,8 @@ func headerMap(t *testing.T, v interface{}) map[string]interface{} { } func TestNewLog_NilConfig(t *testing.T) { - l := NewLog(nil) + l, err := NewLog(nil) + require.NoError(t, err) require.NotNil(t, l) assert.Empty(t, l.maskedHeaders) } @@ -628,18 +651,23 @@ func TestLog_Publish_GlobalFallback_NoPropertiesConfiguredOmitsKey(t *testing.T) // Each Publish call is directed to its own temp file so the two lines can be // decoded independently. func TestLog_Publish_GlobalFallback_PropertiesDoNotLeakAcrossRequests(t *testing.T) { - l := NewLog(&config.TrafficLoggingConfig{ + l, err := NewLog(&config.TrafficLoggingConfig{ Enabled: true, + Outputs: []string{config.TrafficLogSinkStdout}, Properties: map[string]string{"apiName": "$ctx:api.name"}, }) + require.NoError(t, err) require.Nil(t, l.globalDir.Properties, "globalDir must never carry baked-in properties") readOnce := func(event *dto.Event) map[string]interface{} { path := filepath.Join(t.TempDir(), "out.log") f, err := os.Create(path) require.NoError(t, err) - defer f.Close() - l.out = f + // Assert on Close: an error here would mean a write never reached the + // file, which would otherwise surface as a confusing decode failure + // rather than as the write problem it actually is. + defer func() { require.NoError(t, f.Close()) }() + useWriterSink(l, f) l.Publish(event) @@ -667,15 +695,17 @@ func TestLog_Publish_GlobalFallback_PropertiesDoNotLeakAcrossRequests(t *testing // once, each with a different API name, must never race on the shared // l.globalDir. Run with -race to make this meaningful. func TestLog_Publish_GlobalFallback_ConcurrentPropertiesNoRace(t *testing.T) { - l := NewLog(&config.TrafficLoggingConfig{ + l, err := NewLog(&config.TrafficLoggingConfig{ Enabled: true, + Outputs: []string{config.TrafficLogSinkStdout}, Properties: map[string]string{"apiName": "$ctx:api.name"}, }) + require.NoError(t, err) path := filepath.Join(t.TempDir(), "out.log") f, err := os.Create(path) require.NoError(t, err) t.Cleanup(func() { _ = f.Close() }) - l.out = f + useWriterSink(l, f) const n = 50 var wg sync.WaitGroup diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif.go index 6a44fb1fbc..74f99e102d 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif.go @@ -18,6 +18,7 @@ package publishers import ( + "context" "encoding/json" "fmt" "log/slog" @@ -45,6 +46,10 @@ type Moesif struct { mu sync.Mutex done chan struct{} closeOnce sync.Once + // closeErr is the result of the one-and-only shutdown flush, so every caller + // of Close sees the same outcome rather than the second one getting a + // misleading nil. + closeErr error } // MoesifConfig holds the configs specific for the Moesif publisher. @@ -113,15 +118,68 @@ func NewMoesif(moesifCfg *config.MoesifPublisherConfig) *Moesif { return moesif } -// Close stops the background publishing goroutine. -// It should be called when the Moesif publisher is no longer needed. -// Safe to call multiple times. -func (m *Moesif) Close() { +// Close stops the background publishing goroutine and flushes whatever it had +// not yet published, satisfying Closer so Analytics.Close reaches it during +// graceful shutdown. Safe to call multiple times. +// +// Stopping the ticker alone is not enough: events accumulate in m.events between +// ticks, so a shutdown landing mid-interval would abandon up to one full +// interval's worth. They are handed to the client and then flushed, because +// QueueEvents only moves them into the client's own queue — which has its own +// timer and would otherwise be discarded when the process exits. +// +// The flush is bounded by ctx. moesifapi-go v1.1.5 exposes no context or +// configurable timeout on QueueEvents/Flush — Flush is synchronous and subject +// only to the SDK's own HTTP defaults — so it is run on its own goroutine and +// abandoned if ctx expires first. That goroutine may briefly outlive Close; the +// process is exiting, and the alternative is letting an unreachable Moesif +// endpoint hold shutdown open past the operator's budget until the kubelet +// SIGKILLs the pod, which would lose the traffic-log sinks' flush too. +func (m *Moesif) Close(ctx context.Context) error { m.closeOnce.Do(func() { if m.done != nil { close(m.done) } + + // Serialised with the ticker's publish path by the same mutex, so a tick + // already in flight completes first and this then finds the buffer empty + // — each event is queued exactly once. + m.mu.Lock() + pending := m.events + m.events = nil + m.mu.Unlock() + + if m.api == nil { + return + } + + // Buffered so the goroutine can always finish and exit even after ctx + // expired and nobody is left reading. + flushed := make(chan error, 1) + go func() { + var err error + if len(pending) > 0 { + slog.Info("Flushing buffered Moesif events on shutdown", "count", len(pending)) + if qErr := m.api.QueueEvents(pending); qErr != nil { + err = fmt.Errorf("queueing %d buffered event(s) on shutdown: %w", len(pending), qErr) + } + } + m.api.Flush() + flushed <- err + }() + + select { + case err := <-flushed: + m.closeErr = err + case <-ctx.Done(): + m.closeErr = fmt.Errorf("moesif shutdown flush did not complete within the "+ + "shutdown budget; %d buffered event(s) may be lost: %w", len(pending), ctx.Err()) + } + if m.closeErr != nil { + slog.Error("Moesif shutdown flush did not complete cleanly", "error", m.closeErr) + } }) + return m.closeErr } // Publish publishes an event to Moesif. diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif_test.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif_test.go index cf4de09a0b..a447fa990b 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif_test.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/moesif_test.go @@ -18,11 +18,14 @@ package publishers import ( + "context" + "net/http" "os" "sync" "testing" "time" + moesifapi "github.com/moesif/moesifapi-go" "github.com/moesif/moesifapi-go/models" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -122,7 +125,7 @@ func TestNewMoesif_DefaultBaseURL(t *testing.T) { result := NewMoesif(pubCfg) require.NotNil(t, result, "NewMoesif should return a valid publisher") t.Cleanup(func() { - result.Close() + _ = result.Close(context.Background()) }) } @@ -143,7 +146,7 @@ func TestNewMoesif_EnvVarOverridesConfig(t *testing.T) { result := NewMoesif(pubCfg) require.NotNil(t, result, "NewMoesif should return a valid publisher") t.Cleanup(func() { - result.Close() + _ = result.Close(context.Background()) }) } @@ -535,3 +538,114 @@ func TestPublish_SubTypeMirrorsAPIType(t *testing.T) { }) } } + +// fakeMoesifAPI records what Close hands to the client. Only the two methods +// Close exercises do anything; the rest satisfy the interface. +type fakeMoesifAPI struct { + mu sync.Mutex + queued [][]*models.EventModel + flushes int +} + +func (f *fakeMoesifAPI) QueueEvents(e []*models.EventModel) error { + f.mu.Lock() + defer f.mu.Unlock() + f.queued = append(f.queued, e) + return nil +} +func (f *fakeMoesifAPI) Flush() { f.mu.Lock(); f.flushes++; f.mu.Unlock() } +func (f *fakeMoesifAPI) snapshot() (int, int) { + f.mu.Lock() + defer f.mu.Unlock() + n := 0 + for _, b := range f.queued { + n += len(b) + } + return n, f.flushes +} + +func (f *fakeMoesifAPI) QueueEvent(*models.EventModel) error { return nil } +func (f *fakeMoesifAPI) QueueUser(*models.UserModel) error { return nil } +func (f *fakeMoesifAPI) QueueUsers([]*models.UserModel) error { return nil } +func (f *fakeMoesifAPI) QueueCompany(*models.CompanyModel) error { return nil } +func (f *fakeMoesifAPI) QueueCompanies([]*models.CompanyModel) error { return nil } +func (f *fakeMoesifAPI) QueueSubscription(*models.SubscriptionModel) error { return nil } +func (f *fakeMoesifAPI) QueueSubscriptions([]*models.SubscriptionModel) error { return nil } +func (f *fakeMoesifAPI) CreateEvent(*models.EventModel) (http.Header, error) { return nil, nil } +func (f *fakeMoesifAPI) CreateEventsBatch([]*models.EventModel) (http.Header, error) { + return nil, nil +} +func (f *fakeMoesifAPI) UpdateUser(*models.UserModel) error { return nil } +func (f *fakeMoesifAPI) UpdateUsersBatch([]*models.UserModel) error { return nil } +func (f *fakeMoesifAPI) GetAppConfig() (*http.Response, error) { return nil, nil } +func (f *fakeMoesifAPI) UpdateCompany(*models.CompanyModel) error { return nil } +func (f *fakeMoesifAPI) UpdateCompaniesBatch([]*models.CompanyModel) error { return nil } +func (f *fakeMoesifAPI) UpdateSubscription(*models.SubscriptionModel) error { return nil } +func (f *fakeMoesifAPI) UpdateSubscriptionsBatch([]*models.SubscriptionModel) error { return nil } +func (f *fakeMoesifAPI) GetGovernanceRules() (moesifapi.GovernanceRulesResponse, error) { + return moesifapi.GovernanceRulesResponse{}, nil +} +func (f *fakeMoesifAPI) SetEventsHeaderCallback(string, func(string)) {} +func (f *fakeMoesifAPI) Close() {} + +// TestMoesif_CloseFlushesBufferedEvents pins that shutdown does not abandon the +// events accumulated between publish ticks. Close previously only stopped the +// ticker goroutine, so up to one full publish_interval of events was silently +// lost on every restart, rolling update and scale-down. +func TestMoesif_CloseFlushesBufferedEvents(t *testing.T) { + fake := &fakeMoesifAPI{} + m := &Moesif{ + api: fake, + done: make(chan struct{}), + events: []*models.EventModel{{}, {}, {}}, + } + + require.NoError(t, m.Close(context.Background())) + + queued, flushes := fake.snapshot() + assert.Equal(t, 3, queued, "buffered events must be handed to the client on shutdown") + assert.Equal(t, 1, flushes, "the client queue must be flushed, not left to its own timer") + + // Idempotent: a second Close must not re-queue the same events. + require.NoError(t, m.Close(context.Background())) + queued2, _ := fake.snapshot() + assert.Equal(t, 3, queued2, "Close must be idempotent and never double-publish") +} + +// slowMoesifAPI blocks in Flush until released, standing in for an unreachable +// Moesif endpoint. moesifapi-go's Flush is synchronous with no context, so this +// is the only way the sink can be held. +type slowMoesifAPI struct { + fakeMoesifAPI + release chan struct{} +} + +func (s *slowMoesifAPI) Flush() { + <-s.release + s.fakeMoesifAPI.Flush() +} + +// TestMoesif_CloseHonoursShutdownDeadline pins CodeRabbit #2: a hung Moesif +// endpoint must not hold shutdown open past the operator's budget. Doing so +// would also cost the traffic-log sinks their own flush, since Analytics.Close +// runs them in sequence. +func TestMoesif_CloseHonoursShutdownDeadline(t *testing.T) { + api := &slowMoesifAPI{release: make(chan struct{})} + t.Cleanup(func() { close(api.release) }) // let the goroutine finish after the test + m := &Moesif{api: api, done: make(chan struct{}), events: []*models.EventModel{{}}} + + ctx, cancel := context.WithTimeout(context.Background(), 150*time.Millisecond) + defer cancel() + + start := time.Now() + err := m.Close(ctx) + elapsed := time.Since(start) + + require.Error(t, err, "an unfinished flush must be reported, not swallowed") + assert.Contains(t, err.Error(), "shutdown budget") + assert.Less(t, elapsed, time.Second, "Close must return on the deadline, not block on Flush") + + // The error is remembered, so a second Close reports the same outcome rather + // than a misleading nil. + assert.Equal(t, err, m.Close(context.Background())) +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/publisher.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/publisher.go index 1001c932c4..1aaf22d266 100644 --- a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/publisher.go +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/publisher.go @@ -17,9 +17,26 @@ package publishers -import "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/analytics/dto" +import ( + "context" + + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/analytics/dto" +) // Publisher represents an analytics publisher. type Publisher interface { Publish(event *dto.Event) } + +// Closer is implemented by publishers that hold resources or buffer events and +// therefore need to be shut down cleanly. It is kept separate from Publisher so a +// publisher with nothing to release does not have to carry a no-op Close. +// +// Analytics.Close type-asserts each publisher against this interface during +// graceful shutdown. Without it, a buffering publisher loses its in-flight batch on +// every pod restart, rolling update and scale-down. +type Closer interface { + // Close flushes any buffered events and releases resources. It must be + // idempotent and must respect ctx's deadline. + Close(ctx context.Context) error +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink.go new file mode 100644 index 0000000000..e6f5e61534 --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink.go @@ -0,0 +1,210 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "context" + "fmt" + "io" + "log/slog" + "os" + "sync" + "time" + + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/metrics" +) + +// Sink is a destination for serialized traffic-log lines. +// +// Implementations must be safe for concurrent use: Write is called from the ALS +// ingest path, which serves multiple concurrent Envoy access-log streams. +// +// A traffic-log line can carry request and response bodies, so the choice of sink +// is a data-protection decision. Two rules follow from that and apply to every +// implementation: +// +// - A sink that cannot deliver a line drops it and counts it. It must never fall +// back to stdout, which would put the bodies into the container log — the exact +// disclosure a non-stdout sink is configured to prevent. +// - A sink failure must never surface to the client. Traffic logging is strictly +// downstream of request handling. +type Sink interface { + // Write emits one complete JSON line (without a trailing newline; the sink + // adds its own). It must not block the caller for more than a bounded, short + // interval: the caller runs on the access-log ingest path, and blocking there + // backpressures Envoy's ALS stream and eventually Envoy itself. + Write(line []byte) + + // Close flushes anything buffered and releases resources. It must be + // idempotent and must respect ctx's deadline. + Close(ctx context.Context) error + + // Name identifies the sink in log messages and metric labels. It matches the + // corresponding config.TrafficLogSink* constant. + Name() string +} + +// errorLogInterval is the minimum gap between two error log lines from the same +// sink. A sink failure is usually persistent (a full disk, an unreachable +// receiver), so an unthrottled error-per-event would turn one fault into a log +// storm that fills whatever storage is still writable. +const errorLogInterval = 30 * time.Second + +// errThrottle rate-limits repeated error logging from a sink. The zero value is +// ready to use and permits the first call. +type errThrottle struct { + mu sync.Mutex + lastLogged time.Time + suppressed int +} + +// allow reports whether an error should be logged now, and returns the number of +// occurrences suppressed since the previous permitted log so the caller can say +// how much it is hiding. +func (t *errThrottle) allow(now time.Time) (bool, int) { + t.mu.Lock() + defer t.mu.Unlock() + if !t.lastLogged.IsZero() && now.Sub(t.lastLogged) < errorLogInterval { + t.suppressed++ + return false, 0 + } + suppressed := t.suppressed + t.suppressed = 0 + t.lastLogged = now + return true, suppressed +} + +// logError emits a rate-limited error for a sink failure. The line itself is never +// logged: it may contain request/response bodies, so echoing it into the +// application log would reintroduce the very exposure the sink exists to avoid. +func (t *errThrottle) logError(msg, sink string, err error) { + if ok, suppressed := t.allow(time.Now()); ok { + attrs := []any{"sink", sink, "error", err} + if suppressed > 0 { + attrs = append(attrs, "suppressedSinceLastLog", suppressed) + } + slog.Error(msg, attrs...) + } +} + +// writerSink writes each line to an io.Writer, serialized by a mutex so concurrent +// ALS streams cannot interleave partial lines. It backs the stdout sink and is used +// directly by tests to capture output. +type writerSink struct { + mu sync.Mutex + w io.Writer + name string + // closer is called by Close when the underlying writer owns a resource. Nil + // for stdout, which this sink does not own and must not close. + closer io.Closer + throttle errThrottle +} + +// newWriterSink wraps an io.Writer as a Sink. The writer is not closed by Close +// unless it is also passed as closer. +func newWriterSink(w io.Writer, name string, closer io.Closer) *writerSink { + return &writerSink{w: w, name: name, closer: closer} +} + +// newStdoutSink returns the default sink: one JSON line per event on the process's +// stdout. This is the historical behavior and is byte-identical to it. +// +// Note that in the gateway-runtime container the entrypoint wraps the policy +// engine's stdout to prefix every line with "[pol] ", so lines from this sink +// arrive downstream prefixed and are not valid JSON on their own. The file and +// http sinks bypass that wrapper and emit the raw JSON. +func newStdoutSink() *writerSink { + return newWriterSink(os.Stdout, sinkNameStdout, nil) +} + +// Name returns the sink's identifier. +func (s *writerSink) Name() string { return s.name } + +// Write appends the line and a newline to the underlying writer. +func (s *writerSink) Write(line []byte) { + s.mu.Lock() + defer s.mu.Unlock() + if _, err := fmt.Fprintln(s.w, string(line)); err != nil { + mDropped(s.name, dropReasonWriteFailed, 1) + mWriteError(s.name, errCodeWrite, 1) + s.throttle.logError("Failed to write traffic-log event", s.name, err) + return + } + mWritten(s.name, 1) +} + +// Close releases the underlying writer when this sink owns it. Writes go straight +// to the file descriptor with no userspace buffering, so there is nothing to flush. +func (s *writerSink) Close(context.Context) error { + s.mu.Lock() + defer s.mu.Unlock() + if s.closer == nil { + return nil + } + closer := s.closer + s.closer = nil // idempotent: a second Close is a no-op + return closer.Close() +} + +// Metric helpers. +// +// Every traffic-log metric goes through these rather than touching the package +// vars directly. The vars are nil until metrics.Init() runs — main() calls it +// long before any sink exists, but a sink constructor must not depend on that +// ordering, and guarding only in the constructor while the write path +// dereferences freely is worse than either choice made consistently: it turns a +// startup panic into a first-request panic. +// +// The nil check is a single interface comparison against a write path that +// already does a syscall, so the cost is not measurable. + +func mWritten(sink string, n int) { + if metrics.TrafficLogWrittenTotal != nil { + metrics.TrafficLogWrittenTotal.WithLabelValues(sink).Add(float64(n)) + } +} + +func mDropped(sink, reason string, n int) { + if metrics.TrafficLogDroppedTotal != nil { + metrics.TrafficLogDroppedTotal.WithLabelValues(sink, reason).Add(float64(n)) + } +} + +func mWriteError(sink, code string, n int) { + if metrics.TrafficLogWriteErrorsTotal != nil { + metrics.TrafficLogWriteErrorsTotal.WithLabelValues(sink, code).Add(float64(n)) + } +} + +func mQueueDepth(sink string, depth int) { + if metrics.TrafficLogQueueDepth != nil { + metrics.TrafficLogQueueDepth.WithLabelValues(sink).Set(float64(depth)) + } +} + +func mQueueCapacity(sink string, capacity int) { + if metrics.TrafficLogQueueCapacity != nil { + metrics.TrafficLogQueueCapacity.WithLabelValues(sink).Set(float64(capacity)) + } +} + +func mFlushDuration(sink string, seconds float64) { + if metrics.TrafficLogFlushDurationSecond != nil { + metrics.TrafficLogFlushDurationSecond.WithLabelValues(sink).Observe(seconds) + } +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory.go new file mode 100644 index 0000000000..529270cf97 --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory.go @@ -0,0 +1,173 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "context" + "fmt" + "time" + + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" +) + +// Sink names, matching the config.TrafficLogSink* constants. Duplicated as local +// constants so they can be used as metric labels without importing config into +// every call site. +const ( + sinkNameStdout = config.TrafficLogSinkStdout + sinkNameFile = config.TrafficLogSinkFile + sinkNameHTTP = config.TrafficLogSinkHTTP +) + +// Reasons recorded on policy_engine_traffic_log_dropped_total. +const ( + // dropReasonQueueFull: the HTTP sink's bounded queue had no room. + dropReasonQueueFull = "queue_full" + // dropReasonSendFailed: the HTTP sink exhausted its retries. + dropReasonSendFailed = "send_failed" + // dropReasonWriteFailed: a local write returned an error. + dropReasonWriteFailed = "write_failed" + // dropReasonRotateFailed: the file sink could not rotate, so the line that + // triggered the rotation was not written. + dropReasonRotateFailed = "rotate_failed" + // dropReasonBackpressure: the HTTP sink abandoned a batch's remaining retries + // because the queue was filling behind it. Distinct from send_failed so an + // operator can tell "the receiver is slow" from "the receiver is broken". + dropReasonBackpressure = "backpressure" +) + +// Codes recorded on policy_engine_traffic_log_write_errors_total for non-HTTP +// failures. HTTP failures use the numeric status code instead. +const ( + errCodeWrite = "write" + errCodeRotate = "rotate" + errCodeTransport = "transport" +) + +// sinkCleanupTimeout bounds the rollback close when one sink in the set fails to +// build. This is startup, not shutdown: nothing has been written yet, so the +// close should be near-instant and this exists only so a wedged sink cannot mask +// the construction error the operator actually needs to see. +const sinkCleanupTimeout = 5 * time.Second + +// newSinks builds the sink set named by traffic_logging.outputs. +// +// It fails closed: any sink that cannot be constructed returns an error, and the +// caller must refuse to start rather than continue with a partial set. Silently +// dropping an unbuildable file or http sink would leave the operator on stdout — +// putting request and response bodies back into the container log, and therefore +// onto the node's disk and into any node-level collector, which is the exact +// disclosure those sinks are configured to prevent. +// +// Sinks already built are closed before the error is returned, so a failure part +// way through the list does not leak a file descriptor or an orphaned goroutine. +func newSinks(cfg *config.TrafficLoggingConfig) ([]Sink, error) { + outputs, err := config.NormalizeTrafficLogOutputs(cfg.Outputs) + if err != nil { + return nil, err + } + + sinks := make([]Sink, 0, len(outputs)) + closeAll := func() { + // Bounded, and deliberately shared across every sink so the whole cleanup + // is capped rather than each sink getting its own budget. httpSink.Close + // waits for its sender goroutine; an unbounded context here would let a + // failed startup hang instead of reporting the error that caused it. + ctx, cancel := context.WithTimeout(context.Background(), sinkCleanupTimeout) + defer cancel() + for _, s := range sinks { + _ = s.Close(ctx) + } + } + + for _, name := range outputs { + switch name { + case sinkNameStdout: + sinks = append(sinks, newStdoutSink()) + case sinkNameFile: + s, err := newFileSink(cfg.File) + if err != nil { + closeAll() + return nil, fmt.Errorf("traffic_logging.file: %w", err) + } + sinks = append(sinks, s) + case sinkNameHTTP: + s, err := newHTTPSink(cfg.HTTP) + if err != nil { + closeAll() + return nil, fmt.Errorf("traffic_logging.http: %w", err) + } + sinks = append(sinks, s) + default: + // Unreachable: NormalizeTrafficLogOutputs rejects unknown names. + closeAll() + return nil, fmt.Errorf("unsupported traffic_logging.outputs entry %q", name) + } + initSinkMetrics(name) + } + return sinks, nil +} + +// sinkFailureLabels lists the drop reasons and error codes each sink can +// actually produce. Anything a sink cannot emit is deliberately absent, so the +// scrape does not advertise a failure mode that will never occur for it. +var sinkFailureLabels = map[string]struct { + dropReasons []string + errCodes []string +}{ + sinkNameStdout: { + dropReasons: []string{dropReasonWriteFailed}, + errCodes: []string{errCodeWrite}, + }, + sinkNameFile: { + dropReasons: []string{dropReasonWriteFailed, dropReasonRotateFailed}, + errCodes: []string{errCodeWrite, errCodeRotate}, + }, + sinkNameHTTP: { + dropReasons: []string{dropReasonQueueFull, dropReasonSendFailed, dropReasonBackpressure}, + // Only the transport code is pre-created. The HTTP sink also labels by + // response status, and those are unbounded — materializing every + // possible status would be worse than the gap it closes. + errCodes: []string{errCodeTransport}, + }, +} + +// initSinkMetrics materializes a configured sink's counters at zero. +// +// A Prometheus counter with labels does not exist in the scrape until it is +// first incremented, so on a healthy gateway traffic_log_dropped_total is +// simply absent. That makes a dashboard panel read "No data" rather than 0, and +// leaves an operator unable to tell "nothing was dropped" apart from "the +// metrics path is broken" — an unacceptable ambiguity for the one series that +// makes silent traffic-log loss visible. Creating the series up front costs a +// handful of samples and removes the ambiguity. +func initSinkMetrics(sink string) { + // No nil guard needed here: every m* helper is guarded, so this is safe + // before metrics.Init() and consistent with the write paths. + mWritten(sink, 0) + labels, ok := sinkFailureLabels[sink] + if !ok { + return + } + for _, reason := range labels.dropReasons { + mDropped(sink, reason, 0) + } + for _, code := range labels.errCodes { + mWriteError(sink, code, 0) + } +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory_test.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory_test.go new file mode 100644 index 0000000000..41c9d53284 --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_factory_test.go @@ -0,0 +1,298 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "context" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/metrics" +) + +func sinkNames(sinks []Sink) []string { + out := make([]string, 0, len(sinks)) + for _, s := range sinks { + out = append(out, s.Name()) + } + return out +} + +func closeAll(t *testing.T, sinks []Sink) { + t.Helper() + for _, s := range sinks { + _ = s.Close(context.Background()) + } +} + +// Unset outputs must resolve to stdout, so an existing deployment that upgrades +// without touching its config keeps exactly the behavior it had. +func TestNewSinks_DefaultsToStdout(t *testing.T) { + sinks, err := newSinks(&config.TrafficLoggingConfig{Enabled: true}) + require.NoError(t, err) + t.Cleanup(func() { closeAll(t, sinks) }) + assert.Equal(t, []string{config.TrafficLogSinkStdout}, sinkNames(sinks)) +} + +func TestNewSinks_FileOnly(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + sinks, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}, + }) + require.NoError(t, err) + t.Cleanup(func() { closeAll(t, sinks) }) + + assert.Equal(t, []string{config.TrafficLogSinkFile}, sinkNames(sinks)) + assert.NotContains(t, sinkNames(sinks), config.TrafficLogSinkStdout, + "selecting the file sink must take stdout out of the picture entirely") +} + +func TestNewSinks_StdoutAndFile(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + sinks, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkStdout, config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}, + }) + require.NoError(t, err) + t.Cleanup(func() { closeAll(t, sinks) }) + assert.Equal(t, []string{config.TrafficLogSinkStdout, config.TrafficLogSinkFile}, sinkNames(sinks)) +} + +// A typo'd sink name must fail loudly. Silently ignoring it would leave an operator +// who asked for a file sink writing request bodies to the container log. +func TestNewSinks_RejectsUnknownName(t *testing.T) { + _, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{"flie"}, + }) + require.Error(t, err) + assert.Contains(t, err.Error(), "flie") +} + +func TestNewSinks_RejectsDuplicate(t *testing.T) { + _, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkStdout, config.TrafficLogSinkStdout}, + }) + assert.Error(t, err) +} + +// An unusable file sink must fail construction, never silently degrade to stdout. +func TestNewSinks_UnusableFileSinkFailsClosed(t *testing.T) { + _, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: "relative/traffic.log"}, + }) + require.Error(t, err) + assert.Contains(t, err.Error(), "traffic_logging.file") +} + +// A failure part way through the list must not leave earlier sinks open: the file +// created for the first sink has to be closed before the error propagates. +func TestNewSinks_ClosesAlreadyBuiltSinksOnFailure(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + _, err := newSinks(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkFile, config.TrafficLogSinkHTTP}, + File: config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}, + HTTP: config.TrafficLogHTTPConfig{ + // Missing token for the bearer type -> construction fails. + Endpoint: "https://example.invalid/ingest", + QueueCapacity: 10, + BatchMaxEvents: 1, + Auth: config.TrafficLogHTTPAuthConfig{Type: config.TrafficLogAuthBearer}, + }, + }) + require.Error(t, err) + assert.Contains(t, err.Error(), "traffic_logging.http") + + // The file sink was built first, so the file exists; it must have been closed. + _, statErr := os.Stat(path) + assert.NoError(t, statErr) +} + +// Traffic logging disabled means no sink is opened at all: no file is created on +// disk and no sender goroutine is started for a feature nobody enabled. +func TestNewLog_DisabledBuildsNoSinks(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + l, err := NewLog(&config.TrafficLoggingConfig{ + Enabled: false, + Outputs: []string{config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}, + }) + require.NoError(t, err) + assert.Empty(t, l.sinks) + + _, statErr := os.Stat(path) + assert.True(t, os.IsNotExist(statErr), "no file may be created when traffic logging is off") +} + +// NewLog must surface a sink failure so the caller can refuse to start. +func TestNewLog_PropagatesSinkFailure(t *testing.T) { + _, err := NewLog(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: ""}, + }) + assert.Error(t, err) +} + +func TestLog_CloseClosesEverySink(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + l, err := NewLog(&config.TrafficLoggingConfig{ + Enabled: true, + Outputs: []string{config.TrafficLogSinkStdout, config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}, + }) + require.NoError(t, err) + require.NoError(t, l.Close(context.Background())) + require.NoError(t, l.Close(context.Background()), "Close must be idempotent") +} + +// TestNewSinks_MaterializesFailureCountersAtZero guards the ambiguity described +// on initSinkMetrics: without this, traffic_log_dropped_total is absent from the +// scrape on a healthy gateway, so a dashboard cannot distinguish "no drops" from +// "the metrics path is broken". +func TestNewSinks_MaterializesFailureCountersAtZero(t *testing.T) { + reg := metrics.GetRegistry() // TestMain enabled metrics before Init + + dir := t.TempDir() + cfg := &config.TrafficLoggingConfig{ + Outputs: []string{config.TrafficLogSinkStdout, config.TrafficLogSinkFile}, + File: config.TrafficLogFileConfig{Path: filepath.Join(dir, "t.log"), MaxSizeMB: 1}, + } + sinks, err := newSinks(cfg) + require.NoError(t, err) + t.Cleanup(func() { + for _, s := range sinks { + _ = s.Close(context.Background()) + } + }) + + families, err := reg.Gather() + require.NoError(t, err) + // Key on name=value pairs, not positional values: Gather sorts labels by + // label NAME, so a positional key silently reorders (reason before sink). + got := map[string]bool{} + for _, f := range families { + for _, m := range f.GetMetric() { + key := f.GetName() + for _, l := range m.GetLabel() { + key += "|" + l.GetName() + "=" + l.GetValue() + } + got[key] = true + } + } + + // Present at zero for every configured sink, before anything is written. + for _, want := range []string{ + "policy_engine_traffic_log_dropped_total|reason=write_failed|sink=stdout", + "policy_engine_traffic_log_dropped_total|reason=write_failed|sink=file", + "policy_engine_traffic_log_dropped_total|reason=rotate_failed|sink=file", + "policy_engine_traffic_log_write_errors_total|code=rotate|sink=file", + "policy_engine_traffic_log_write_errors_total|code=write|sink=stdout", + "policy_engine_traffic_log_written_total|sink=file", + "policy_engine_traffic_log_written_total|sink=stdout", + } { + assert.True(t, got[want], "series %q must exist at zero on a healthy gateway", want) + } + // Capacity must be published so the backlog alert can be a ratio. + assert.False(t, got["policy_engine_traffic_log_queue_capacity|sink=http"], + "no http sink was configured, so no capacity should be published") + + // A sink that was not configured must NOT appear — an operator reading the + // scrape should see only the sinks actually in use. + assert.False(t, got["policy_engine_traffic_log_dropped_total|reason=queue_full|sink=http"], + "an unconfigured sink must not be advertised") +} + +// TestNewSinks_PublishesQueueCapacity pins the metric the TrafficLogQueueBacklog +// alert divides by. A fixed depth threshold cannot work across deployments: 1000 +// is 10% of the default 10000 queue but unreachable on a queue configured +// smaller, so the alert has to compare depth against this. +func TestNewSinks_PublishesQueueCapacity(t *testing.T) { + srv := httptest.NewServer(&receiver{status: http.StatusOK}) + t.Cleanup(srv.Close) + + cfg := &config.TrafficLoggingConfig{ + Outputs: []string{config.TrafficLogSinkHTTP}, + HTTP: httpSinkCfg(srv.URL), + } + cfg.HTTP.QueueCapacity = 4242 + sinks, err := newSinks(cfg) + require.NoError(t, err) + t.Cleanup(func() { + for _, s := range sinks { + _ = s.Close(context.Background()) + } + }) + + families, err := metrics.GetRegistry().Gather() + require.NoError(t, err) + var got float64 + for _, f := range families { + if f.GetName() != "policy_engine_traffic_log_queue_capacity" { + continue + } + for _, m := range f.GetMetric() { + for _, l := range m.GetLabel() { + if l.GetName() == "sink" && l.GetValue() == config.TrafficLogSinkHTTP { + got = m.GetGauge().GetValue() + } + } + } + } + assert.Equal(t, float64(4242), got, + "the configured queue_capacity must be published as a gauge") +} + +// TestNewSinks_CleanupIsBounded pins CodeRabbit #3: the rollback close when a +// later sink fails to build uses a bounded context, so a wedged sink cannot hang +// startup and hide the construction error the operator needs to see. +func TestNewSinks_CleanupIsBounded(t *testing.T) { + srv := httptest.NewServer(&receiver{status: http.StatusOK}) + t.Cleanup(srv.Close) + + // http builds, file then fails on a relative path -> closeAll runs. + cfg := &config.TrafficLoggingConfig{ + Outputs: []string{config.TrafficLogSinkHTTP, config.TrafficLogSinkFile}, + HTTP: httpSinkCfg(srv.URL), + File: config.TrafficLogFileConfig{Path: "relative/traffic.log"}, + } + done := make(chan error, 1) + go func() { _, err := newSinks(cfg); done <- err }() + + select { + case err := <-done: + require.Error(t, err) + assert.Contains(t, err.Error(), "traffic_logging.file") + case <-time.After(sinkCleanupTimeout + 5*time.Second): + t.Fatal("newSinks did not return: the cleanup close is not bounded") + } +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file.go new file mode 100644 index 0000000000..429bd5c5ee --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file.go @@ -0,0 +1,226 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "context" + "fmt" + "log/slog" + "os" + "path/filepath" + "sync" + + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" +) + +const ( + // trafficLogFileMode is the mode of the live log file and every rotated + // backup. The file holds request and response bodies, so it is owner-only. + // It is deliberately not configurable: 0600 is the only defensible value for + // this content, and a knob would only create a way to get it wrong. + trafficLogFileMode os.FileMode = 0o600 + // trafficLogDirMode is the mode of the containing directory, created if + // absent. Both modes are established at creation time rather than chmod'd + // afterwards, which would leave a window where the file is world-readable. + trafficLogDirMode os.FileMode = 0o700 + // rotatedSuffix is appended to the live path to form the single backup. + rotatedSuffix = ".1" + // bytesPerMiB converts the configured max_size_mb into bytes. + bytesPerMiB int64 = 1 << 20 +) + +// fileSink appends each traffic-log line to a local file, rotating at a size +// ceiling. It exists so request/response bodies never reach the container's stdout +// — and therefore never reach the node's /var/log/pods files, where every +// node-level log collector (DaemonSet agent, host forwarder) would pick them up +// unredacted. +// +// Rotation keeps exactly one backup: the live file is renamed to .1, +// clobbering any previous backup, and a fresh file is opened. Worst-case on-disk +// total is therefore 2 x maxBytes. That is deliberately simpler than a general +// logging library — this sink is the only writer to the file, so there is no +// concurrent-rotation case to handle, and each additional backup would be another +// copy of PII at rest. +// +// Rename-then-recreate is logrotate's "create" mode, which a tailing reader such as +// Fluent Bit follows correctly via inode tracking. +type fileSink struct { + mu sync.Mutex + f *os.File + path string + // size tracks the live file's length in bytes. It is seeded from Stat at open + // so an append to a file left behind by a previous run is accounted for, and + // maintained from write results afterwards — this sink is the only writer, so + // a per-write Stat would be wasted work. + size int64 + // maxBytes is the rotation threshold. 0 disables rotation. + maxBytes int64 + throttle errThrottle +} + +// newFileSink opens (creating if needed) the configured traffic-log file. +// +// It returns an error rather than degrading: a file sink that cannot be opened must +// fail startup, never silently leave the operator writing bodies to stdout. +// config.Validate has already performed this same open during startup validation, +// so a failure here means the environment changed underneath us in the interim. +func newFileSink(cfg config.TrafficLogFileConfig) (*fileSink, error) { + path, err := config.ResolveTrafficLogFilePath(cfg.Path) + if err != nil { + return nil, err + } + if cfg.MaxSizeMB < 0 { + return nil, fmt.Errorf("max_size_mb must be >= 0, got %d", cfg.MaxSizeMB) + } + + if err := os.MkdirAll(filepath.Dir(path), trafficLogDirMode); err != nil { + return nil, fmt.Errorf("cannot create directory for %q: %w", path, err) + } + f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, trafficLogFileMode) + if err != nil { + return nil, fmt.Errorf("cannot open %q for append: %w", path, err) + } + // A pre-existing file or directory kept its old mode: O_CREATE and MkdirAll + // only apply theirs when they create. Refuse to write bodies into something + // group- or world-readable. + if err := config.VerifyTrafficLogPerms(f, path); err != nil { + _ = f.Close() + return nil, err + } + info, err := f.Stat() + if err != nil { + _ = f.Close() + return nil, fmt.Errorf("cannot stat %q: %w", path, err) + } + + s := &fileSink{ + f: f, + path: path, + size: info.Size(), + maxBytes: int64(cfg.MaxSizeMB) * bytesPerMiB, + } + slog.Info("Traffic logging file sink ready", + "path", path, "maxSizeMB", cfg.MaxSizeMB, "existingBytes", info.Size()) + return s, nil +} + +// Name returns the sink's identifier. +func (s *fileSink) Name() string { return sinkNameFile } + +// Write appends the line, rotating first if it would push the file past the size +// ceiling. A failure drops the line and counts it; it never falls back to stdout +// and never surfaces to the request path. +func (s *fileSink) Write(line []byte) { + s.mu.Lock() + defer s.mu.Unlock() + + if s.f == nil { // closed + mDropped(sinkNameFile, dropReasonWriteFailed, 1) + return + } + + // The s.size > 0 guard matters for a line larger than the whole ceiling: it + // must land in a freshly rotated file and stay there, rather than triggering a + // rotation on every subsequent write and churning the backup away each time. + if s.maxBytes > 0 && s.size > 0 && s.size+int64(len(line))+1 > s.maxBytes { + if err := s.rotate(); err != nil { + mWriteError(sinkNameFile, errCodeRotate, 1) + if s.f == nil { + // No usable handle: the line genuinely cannot be written. + mDropped(sinkNameFile, dropReasonRotateFailed, 1) + s.throttle.logError("Failed to rotate traffic-log file; dropping event", sinkNameFile, err) + return + } + // Rotation failed but the file is still writable — typically a + // read-only parent directory blocking the rename. Keep writing + // unrotated rather than dropping. The file may now exceed + // max_size_mb, which is why this is logged as an error and counted. + s.throttle.logError("Failed to rotate traffic-log file; continuing to write "+ + "unrotated, so the file may exceed max_size_mb", sinkNameFile, err) + } + } + + n, err := fmt.Fprintln(s.f, string(line)) + // n counts whatever reached the file even on a short write, so add it before + // handling the error: otherwise a series of short writes would drift s.size + // below the real length and defeat the rotation threshold. + s.size += int64(n) + if err != nil { + mDropped(sinkNameFile, dropReasonWriteFailed, 1) + mWriteError(sinkNameFile, errCodeWrite, 1) + s.throttle.logError("Failed to write traffic-log event to file; dropping event", sinkNameFile, err) + return + } + mWritten(sinkNameFile, 1) +} + +// rotate renames the live file to .1 and reopens a fresh one. Callers must +// hold s.mu. +// +// On failure the sink is left with a usable file wherever possible: if the rename +// fails, the original handle is reopened so writing continues (unrotated) rather +// than the sink going permanently dead and losing every subsequent event. +func (s *fileSink) rotate() error { + // Retain a Close error rather than returning on it. Returning early would + // leave s.f pointing at a descriptor Close has already released, so every + // later write would fail against a dead handle with no attempt to recover. + // Clearing it and continuing to the reopen below gets the sink working again. + closeErr := s.f.Close() + s.f = nil + + renameErr := os.Rename(s.path, s.path+rotatedSuffix) + + // Reopen regardless of the rename result. After a successful rename this + // creates a new empty file; after a failed one it reattaches to the existing + // file so the sink keeps working instead of dropping everything from here on. + f, err := os.OpenFile(s.path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, trafficLogFileMode) + if err != nil { + return fmt.Errorf("reopening after rotation: %w", err) + } + info, err := f.Stat() + if err != nil { + _ = f.Close() + return fmt.Errorf("stat after rotation: %w", err) + } + s.f = f + s.size = info.Size() + + if renameErr != nil { + return fmt.Errorf("renaming to %s: %w", s.path+rotatedSuffix, renameErr) + } + if closeErr != nil { + // Rotation completed, but the old descriptor did not close cleanly — worth + // surfacing, and Write treats it as degraded-but-writable since s.f is set. + return fmt.Errorf("closing live file before rotation: %w", closeErr) + } + return nil +} + +// Close closes the live file. Writes are unbuffered in userspace, so anything +// already written is in the page cache and needs no flush; Close exists to release +// the descriptor. Safe to call more than once. +func (s *fileSink) Close(context.Context) error { + s.mu.Lock() + defer s.mu.Unlock() + if s.f == nil { + return nil + } + f := s.f + s.f = nil + return f.Close() +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file_test.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file_test.go new file mode 100644 index 0000000000..584154648d --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_file_test.go @@ -0,0 +1,307 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "bytes" + "context" + "fmt" + "os" + "path/filepath" + "strings" + "sync" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" +) + +func fileSinkCfg(path string, maxSizeMB int) config.TrafficLogFileConfig { + return config.TrafficLogFileConfig{Path: path, MaxSizeMB: maxSizeMB} +} + +func readFileLines(t *testing.T, path string) []string { + t.Helper() + data, err := os.ReadFile(path) + require.NoError(t, err) + trimmed := strings.TrimRight(string(data), "\n") + if trimmed == "" { + return nil + } + return strings.Split(trimmed, "\n") +} + +func TestFileSink_WritesLines(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 100)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"a":1}`)) + s.Write([]byte(`{"b":2}`)) + + assert.Equal(t, []string{`{"a":1}`, `{"b":2}`}, readFileLines(t, path)) + assert.Equal(t, config.TrafficLogSinkFile, s.Name()) +} + +// The file carries request/response bodies, so the mode must be owner-only and +// must be established at creation rather than chmod'd afterwards. +func TestFileSink_CreatesRestrictivePermissions(t *testing.T) { + dir := filepath.Join(t.TempDir(), "nested", "traffic") + path := filepath.Join(dir, "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 100)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + fi, err := os.Stat(path) + require.NoError(t, err) + assert.Equal(t, os.FileMode(0o600), fi.Mode().Perm(), "traffic log must be owner read/write only") + + di, err := os.Stat(dir) + require.NoError(t, err) + assert.Equal(t, os.FileMode(0o700), di.Mode().Perm(), "traffic log directory must be owner-only") +} + +func TestFileSink_RejectsBadPaths(t *testing.T) { + for name, path := range map[string]string{ + "empty": "", + "relative": "relative/traffic.log", + "null byte": "/tmp/traf\x00fic.log", + } { + t.Run(name, func(t *testing.T) { + _, err := newFileSink(fileSinkCfg(path, 100)) + assert.Error(t, err) + }) + } +} + +// Rotation renames the live file aside and reopens, keeping exactly one backup, so +// the on-disk total stays bounded at 2 x max_size_mb. +func TestFileSink_RotatesAtCeiling(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 1)) // 1 MiB + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + line := []byte(strings.Repeat("x", 100*1024)) // 100 KiB + newline + for i := 0; i < 12; i++ { // ~1.2 MiB total -> one rotation + s.Write(line) + } + + backup := path + rotatedSuffix + require.FileExists(t, backup, "rotation must leave exactly one backup") + + live, err := os.Stat(path) + require.NoError(t, err) + assert.Less(t, live.Size(), int64(bytesPerMiB), "live file must be under the ceiling after rotation") + + rotated, err := os.Stat(backup) + require.NoError(t, err) + assert.Equal(t, os.FileMode(0o600), rotated.Mode().Perm(), "rotation must not widen permissions") + assert.Equal(t, os.FileMode(0o600), live.Mode().Perm()) +} + +// A second rotation clobbers the previous backup rather than accumulating: each +// extra backup would be another copy of PII at rest. +func TestFileSink_SecondRotationClobbersBackup(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 1)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + line := []byte(strings.Repeat("y", 100*1024)) + for i := 0; i < 25; i++ { // ~2.5 MiB -> two rotations + s.Write(line) + } + + entries, err := os.ReadDir(dir) + require.NoError(t, err) + assert.Len(t, entries, 2, "only the live file and a single backup may exist") +} + +// A line larger than the whole ceiling must land in a freshly rotated file and stay +// there — not trigger a rotation on every subsequent write. +func TestFileSink_OversizedLineDoesNotChurnRotations(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 1)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + oversized := []byte(strings.Repeat("z", 2*int(bytesPerMiB))) + s.Write(oversized) // size was 0, so no rotation; file is now over the ceiling + s.Write(oversized) // rotates once, then writes + + entries, err := os.ReadDir(dir) + require.NoError(t, err) + assert.Len(t, entries, 2) + + lines := readFileLines(t, path) + require.Len(t, lines, 1, "the oversized line must be present, not dropped") + assert.Len(t, lines[0], 2*int(bytesPerMiB)) +} + +// After a restart the sink appends to whatever the previous run left behind, and +// must seed its size counter from the file so the ceiling still binds. +func TestFileSink_SeedsSizeFromExistingFile(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + require.NoError(t, os.WriteFile(path, []byte(strings.Repeat("a", 900*1024)+"\n"), 0o600)) + + s, err := newFileSink(fileSinkCfg(path, 1)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + assert.Greater(t, s.size, int64(900*1024), "size must be seeded from the existing file") + + s.Write([]byte(strings.Repeat("b", 200*1024))) // pushes past 1 MiB -> rotates + require.FileExists(t, path+rotatedSuffix) +} + +func TestFileSink_MaxSizeZeroDisablesRotation(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 0)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + line := []byte(strings.Repeat("q", 200*1024)) + for i := 0; i < 10; i++ { + s.Write(line) + } + + entries, err := os.ReadDir(dir) + require.NoError(t, err) + assert.Len(t, entries, 1, "rotation disabled -> no backup should ever appear") +} + +func TestFileSink_CloseIsIdempotentAndStopsWrites(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 100)) + require.NoError(t, err) + + s.Write([]byte(`{"before":true}`)) + require.NoError(t, s.Close(context.Background())) + require.NoError(t, s.Close(context.Background()), "Close must be idempotent") + + s.Write([]byte(`{"after":true}`)) // must not panic + assert.Equal(t, []string{`{"before":true}`}, readFileLines(t, path)) +} + +func TestFileSink_ConcurrentWritesProduceWholeLines(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 100)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + const n = 100 + var wg sync.WaitGroup + wg.Add(n) + for i := 0; i < n; i++ { + go func(i int) { + defer wg.Done() + s.Write([]byte(fmt.Sprintf(`{"i":%d}`, i))) + }(i) + } + wg.Wait() + + lines := readFileLines(t, path) + assert.Len(t, lines, n) + for _, line := range lines { + assert.True(t, strings.HasPrefix(line, `{"i":`) && strings.HasSuffix(line, `}`), + "concurrent writes must not interleave: got %q", line) + } +} + +// The entrypoint prefixes the policy engine's stdout with "[pol] ", which is what +// forced a fragile strip-the-prefix parser downstream and previously let an +// unparsed line through. The file sink bypasses that wrapper, so what lands on disk +// must be the raw JSON with no prefix of any kind. +func TestFileSink_WritesRawJSONWithoutComponentPrefix(t *testing.T) { + path := filepath.Join(t.TempDir(), "traffic.log") + s, err := newFileSink(fileSinkCfg(path, 100)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"requestBody":"hello"}`)) + + lines := readFileLines(t, path) + require.Len(t, lines, 1) + assert.Equal(t, `{"requestBody":"hello"}`, lines[0]) + assert.NotContains(t, lines[0], "[pol]") +} + +// TestFileSink_RenameFailureKeepsWriting pins the recovery rotate() documents. +// Previously rotate() reopened a usable handle but still returned the rename +// error, and Write dropped on ANY error — so the "keep working" path dropped +// every subsequent line, exactly what it claimed to avoid. +func TestFileSink_RenameFailureKeepsWriting(t *testing.T) { + if os.Geteuid() == 0 { + // root ignores directory permissions, so the rename would succeed and + // this test would assert the opposite of what it is checking. + t.Skip("running as root: directory permission checks do not apply") + } + dir := t.TempDir() + path := filepath.Join(dir, "traffic.log") + s, err := newFileSink(config.TrafficLogFileConfig{Path: path, MaxSizeMB: 1}) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + // Push past the ceiling so the next write attempts a rotation. + big := bytes.Repeat([]byte("x"), 1<<20) + s.Write(big) + + // Renaming needs write permission on the DIRECTORY; appending to the + // already-open file does not. This makes rotation fail while leaving the + // sink perfectly able to write. + require.NoError(t, os.Chmod(dir, 0o500)) + t.Cleanup(func() { _ = os.Chmod(dir, 0o700) }) + + before, err := os.Stat(path) + require.NoError(t, err) + s.Write([]byte(`{"after":"rename-failure"}`)) + after, err := os.Stat(path) + require.NoError(t, err) + + assert.Greater(t, after.Size(), before.Size(), + "a line must still be written when rotation fails but the handle is usable") + assert.NoFileExists(t, path+rotatedSuffix, "the rename did not succeed, so no backup should exist") +} + +// TestFileSink_RejectsPreExistingPermissiveFile pins CodeRabbit #4: O_CREATE +// applies its mode only when it creates, so a file left behind by an earlier run +// keeps its old mode. A world-readable file holding request and response bodies +// defeats the reason for choosing this sink, so construction must fail. +func TestFileSink_RejectsPreExistingPermissiveFile(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("running as root: permission checks do not apply") + } + dir := t.TempDir() + path := filepath.Join(dir, "traffic.log") + require.NoError(t, os.WriteFile(path, []byte("from a previous run\n"), 0o644)) + + _, err := newFileSink(config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}) + require.Error(t, err, "a group/other-readable traffic log must not be opened") + assert.Contains(t, err.Error(), "chmod 600", "the error must say how to fix it") + + // Tightening it makes the same path acceptable. + require.NoError(t, os.Chmod(path, 0o600)) + s, err := newFileSink(config.TrafficLogFileConfig{Path: path, MaxSizeMB: 10}) + require.NoError(t, err) + _ = s.Close(context.Background()) +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http.go new file mode 100644 index 0000000000..690eff18c0 --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http.go @@ -0,0 +1,604 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "bytes" + "context" + "crypto/tls" + "crypto/x509" + "errors" + "fmt" + "io" + "log/slog" + "math/rand/v2" + "net/http" + "os" + "strconv" + "strings" + "sync" + "time" + + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" +) + +const ( + // maxErrorBodyBytes caps how much of a receiver's error response is read + // before being discarded. A receiver returning an enormous error body must not + // be able to grow the gateway's heap. + maxErrorBodyBytes int64 = 4 << 10 + // retryAfterCap bounds how long a receiver's Retry-After header can stall the + // sender. Without it, a hostile or misconfigured receiver could park the + // sending goroutine indefinitely while the queue overflows. + retryAfterCap = 30 * time.Second +) + +// httpSink batches traffic-log lines and POSTs them to an operator-named endpoint. +// +// It exists for deployments that cannot run a co-located log collector — no +// sidecar, no node-level agent, no access to the node filesystem. Nothing is +// written to disk at any point. +// +// Delivery semantics, and the reasoning behind them: +// +// - Write never blocks. It runs on the ALS ingest path, so blocking there +// backpressures Envoy's access-log stream and eventually Envoy itself. A line +// that does not fit in the queue is dropped and counted. +// - The queue is bounded. An unbounded queue in front of a bounded sender is +// just deferred unbounded memory growth, and these lines carry request and +// response bodies, so the growth would be fast. +// - A delivery failure drops the batch. It is never written to stdout instead: +// that would put the bodies into the container log, which is what this sink +// exists to avoid. +// +// The consequence worth stating plainly to an operator: unlike a Fluent Bit or +// OpenTelemetry collector, which buffer to disk, this sink's queue is memory-only. +// A receiver outage costs events rather than merely delaying them. That is the +// deliberate trade for never touching the disk, and +// policy_engine_traffic_log_dropped_total is the series that makes it visible. +type httpSink struct { + cfg config.TrafficLogHTTPConfig + client *http.Client + + // authHeader is the pre-computed header name/value applied to every request, + // resolved once at construction. Empty name means no authentication. The value + // is a secret and is never logged. + authHeaderName string + authHeaderValue string + + // queue carries serialized lines from Write to the sender goroutine. + queue chan []byte + // dropOldest selects the eviction policy when the queue is full. + dropOldest bool + // retryAbortDepth is the queue depth at which a retrying batch gives up so the + // sender can resume draining. See the note in deliver. + retryAbortDepth int + + // done is closed by Close to stop the sender goroutine. + done chan struct{} + // stopped is closed by the sender goroutine once its final flush completes, + // so Close can wait for it (bounded by the caller's context). + stopped chan struct{} + closeOnce sync.Once + + throttle errThrottle +} + +// newHTTPSink builds the sink and starts its sender goroutine. +// +// It returns an error rather than degrading: an HTTP sink that cannot be built must +// fail startup, never silently leave the operator writing bodies to stdout. +func newHTTPSink(cfg config.TrafficLogHTTPConfig) (*httpSink, error) { + // config.Validate already rejects these, but this constructor is documented + // fail-closed and must behave that way for any caller. Without the check a + // non-positive FlushInterval panics inside time.NewTicker and a negative + // QueueCapacity panics in make — a panic is not failing closed. + if cfg.FlushInterval <= 0 { + return nil, fmt.Errorf("flush_interval must be positive, got %s", cfg.FlushInterval) + } + if cfg.RequestTimeout <= 0 { + return nil, fmt.Errorf("request_timeout must be positive, got %s", cfg.RequestTimeout) + } + if cfg.QueueCapacity <= 0 { + return nil, fmt.Errorf("queue_capacity must be positive, got %d", cfg.QueueCapacity) + } + if cfg.BatchMaxEvents <= 0 { + return nil, fmt.Errorf("batch_max_events must be positive, got %d", cfg.BatchMaxEvents) + } + if cfg.BatchMaxBytes <= 0 { + return nil, fmt.Errorf("batch_max_bytes must be positive, got %d", cfg.BatchMaxBytes) + } + if cfg.MaxRetries < 0 { + return nil, fmt.Errorf("max_retries must not be negative, got %d", cfg.MaxRetries) + } + + tlsCfg, err := buildTrafficLogTLSConfig(cfg.TLS) + if err != nil { + return nil, err + } + name, value, err := buildTrafficLogAuthHeader(cfg.Auth) + if err != nil { + return nil, err + } + + s := &httpSink{ + cfg: cfg, + client: &http.Client{ + Timeout: cfg.RequestTimeout, + Transport: &http.Transport{ + TLSClientConfig: tlsCfg, + MaxIdleConnsPerHost: 2, + IdleConnTimeout: 90 * time.Second, + }, + // Never auto-follow a redirect: the redirect target is chosen by the + // receiver, not the operator, and following it would send request and + // response bodies to a destination nobody configured. + CheckRedirect: func(*http.Request, []*http.Request) error { + return http.ErrUseLastResponse + }, + }, + authHeaderName: name, + authHeaderValue: value, + queue: make(chan []byte, cfg.QueueCapacity), + dropOldest: strings.EqualFold(strings.TrimSpace(cfg.OnQueueFull), + config.TrafficLogQueueDropOldest), + done: make(chan struct{}), + stopped: make(chan struct{}), + // Below this, retrying is free — nothing is being lost + // while we wait. At or above it, the queue is filling faster than we are + // draining and every further second of retry costs events. + retryAbortDepth: cfg.EffectiveRetryAbortDepth(), + } + + // Publish the configured bound so an alert can express "the queue is 80% + // full" as a ratio against queue_depth. A fixed depth threshold is wrong at + // every capacity but one. Set here, next to the config it describes, rather + // than in the factory — otherwise any sink built by another path reports a + // depth with nothing to divide it by. + mQueueCapacity(sinkNameHTTP, cfg.QueueCapacity) + + go s.run() + slog.Info("Traffic logging HTTP sink ready", + "endpoint", cfg.Endpoint, + "queueCapacity", cfg.QueueCapacity, + "batchMaxEvents", cfg.BatchMaxEvents, + "flushInterval", cfg.FlushInterval) + return s, nil +} + +// Name returns the sink's identifier. +func (s *httpSink) Name() string { return sinkNameHTTP } + +// Write enqueues the line for delivery. It never blocks: on a full queue it drops +// according to the configured policy and returns immediately. +// +// The line is copied because the caller owns the underlying array and reuses it +// after Publish returns; without the copy a queued line could be rewritten before +// the sender serializes it. +func (s *httpSink) Write(line []byte) { + // After Close the sender goroutine is gone, so anything accepted here would + // sit in the queue forever — delivered to nobody and counted as nothing. Fail + // it explicitly instead, matching the file sink's closed-handle behaviour. + select { + case <-s.done: + mDropped(sinkNameHTTP, dropReasonSendFailed, 1) + return + default: + } + + queued := make([]byte, len(line)) + copy(queued, line) + + select { + case s.queue <- queued: + mQueueDepth(sinkNameHTTP, len(s.queue)) + return + default: + } + + if s.dropOldest { + // Evict one old line and retry once. A single attempt is deliberate: a + // loop here could spin while producers keep the queue full, turning a + // non-blocking Write into an unbounded one. + select { + case <-s.queue: + mDropped(sinkNameHTTP, dropReasonQueueFull, 1) + default: + } + select { + case s.queue <- queued: + mQueueDepth(sinkNameHTTP, len(s.queue)) + return + default: + } + } + + mDropped(sinkNameHTTP, dropReasonQueueFull, 1) + s.throttle.logError("Traffic-log HTTP queue is full; dropping event", sinkNameHTTP, + fmt.Errorf("queue capacity %d exhausted", s.cfg.QueueCapacity)) +} + +// run is the sender goroutine: it accumulates lines into a batch and delivers when +// any bound is reached, then performs one final flush on shutdown. +func (s *httpSink) run() { + defer func() { + // A Write can win the race against the done-check above and enqueue just + // as the drain finishes. Account for anything left rather than letting it + // vanish: silent loss is the one outcome the drop counter exists to rule + // out. + for { + select { + case <-s.queue: + mDropped(sinkNameHTTP, dropReasonSendFailed, 1) + continue + default: + } + break + } + mQueueDepth(sinkNameHTTP, 0) + close(s.stopped) + }() + + ticker := time.NewTicker(s.cfg.FlushInterval) + defer ticker.Stop() + + batch := make([][]byte, 0, s.cfg.BatchMaxEvents) + batchBytes := 0 + + flush := func() { + if len(batch) == 0 { + return + } + s.deliver(batch) + batch = make([][]byte, 0, s.cfg.BatchMaxEvents) + batchBytes = 0 + } + + for { + select { + case <-s.done: + // Drain whatever is still queued so a graceful shutdown does not lose + // events that were accepted but not yet sent. + for { + select { + case line := <-s.queue: + batch = append(batch, line) + batchBytes += len(line) + 1 + if len(batch) >= s.cfg.BatchMaxEvents || batchBytes >= s.cfg.BatchMaxBytes { + flush() + } + continue + default: + } + break + } + flush() + return + + case line := <-s.queue: + mQueueDepth(sinkNameHTTP, len(s.queue)) + batch = append(batch, line) + batchBytes += len(line) + 1 + if len(batch) >= s.cfg.BatchMaxEvents || batchBytes >= s.cfg.BatchMaxBytes { + flush() + } + + case <-ticker.C: + flush() + } + } +} + +// deliver POSTs one batch, retrying transport errors, 429 and 5xx with jittered +// exponential backoff. A 4xx other than 429 is not retried: it means the receiver +// rejected the batch's shape, so retrying would only amplify a permanent failure. +func (s *httpSink) deliver(batch [][]byte) { + body := encodeNDJSON(batch) + start := time.Now() + defer func() { + mFlushDuration(sinkNameHTTP, time.Since(start).Seconds()) + }() + + var lastErr error + // Delay to apply before the NEXT attempt. A receiver-supplied Retry-After + // replaces our own backoff rather than adding to it: sleeping both made a + // "Retry-After: 2" wait 2s + the exponential delay, ignoring the receiver's + // own pacing and holding the batch longer than it asked for. + var nextDelay time.Duration + for attempt := 0; attempt <= s.cfg.MaxRetries; attempt++ { + if attempt > 0 { + // Head-of-line check, before committing to another wait. + // + // There is one sender goroutine, and deliver runs inside its select + // loop, so nothing drains the queue while a batch is retrying. With the + // defaults a batch against a receiver that accepts and never answers + // holds the sender for 43-47s (4 attempts x request_timeout plus + // jittered backoff), and up to ~130s if the receiver returns 429 with a + // large Retry-After. At even a modest event rate that is long enough to + // fill the whole queue, so retrying to save ~batch_max_events costs + // thousands of newer events to queue_full. + // + // Retrying is only worth it while nothing else is being lost. Once the + // queue is past the high-water mark, abandon this batch and get back to + // draining — one batch lost deliberately instead of an unbounded number + // lost as a side effect. + if depth := len(s.queue); depth >= s.retryAbortDepth { + mDropped(sinkNameHTTP, dropReasonBackpressure, len(batch)) + s.throttle.logError("Abandoning traffic-log batch retries to resume draining; "+ + "the receiver is accepting but too slow to keep up", sinkNameHTTP, + fmt.Errorf("%d event(s) dropped after %d attempt(s) with queue at %d/%d: %w", + len(batch), attempt, depth, s.cfg.QueueCapacity, lastErr)) + return + } + + delay := nextDelay + if delay <= 0 { + delay = s.backoff(attempt) + } + if !s.sleep(delay) { + break // shutting down; stop retrying and drop + } + } + + retryAfter, err := s.post(body) + if err == nil { + mWritten(sinkNameHTTP, len(batch)) + return + } + lastErr = err + + var perm *permanentDeliveryError + if errors.As(err, &perm) { + break // 4xx — retrying cannot help + } + nextDelay = retryAfter // 0 unless the receiver asked for a specific delay + } + + mDropped(sinkNameHTTP, dropReasonSendFailed, len(batch)) + s.throttle.logError("Failed to deliver traffic-log batch; dropping events", sinkNameHTTP, + fmt.Errorf("%d event(s) dropped after %d attempt(s): %w", len(batch), s.cfg.MaxRetries+1, lastErr)) +} + +// permanentDeliveryError marks a response that must not be retried. +type permanentDeliveryError struct{ status int } + +func (e *permanentDeliveryError) Error() string { + return fmt.Sprintf("receiver rejected the batch with status %d", e.status) +} + +// post performs one delivery attempt. It returns the receiver's requested +// Retry-After delay when it supplies one, so the caller can honor it instead of its +// own backoff. +func (s *httpSink) post(body []byte) (time.Duration, error) { + ctx, cancel := context.WithTimeout(context.Background(), s.cfg.RequestTimeout) + defer cancel() + + req, err := http.NewRequestWithContext(ctx, http.MethodPost, s.cfg.Endpoint, bytes.NewReader(body)) + if err != nil { + return 0, fmt.Errorf("building request: %w", err) + } + req.Header.Set("Content-Type", s.cfg.ContentType) + if s.authHeaderName != "" { + req.Header.Set(s.authHeaderName, s.authHeaderValue) + } + + resp, err := s.client.Do(req) + if err != nil { + mWriteError(sinkNameHTTP, errCodeTransport, 1) + // The error can embed the endpoint URL but never the body, so no + // request/response payload can leak into the application log here. + return 0, fmt.Errorf("posting batch: %w", err) + } + defer resp.Body.Close() + + // Drain a bounded prefix so the connection can be reused, and discard the rest. + _, _ = io.Copy(io.Discard, io.LimitReader(resp.Body, maxErrorBodyBytes)) + + if resp.StatusCode >= 200 && resp.StatusCode < 300 { + return 0, nil + } + mWriteError(sinkNameHTTP, strconv.Itoa(resp.StatusCode), 1) + + if resp.StatusCode == http.StatusTooManyRequests { + return parseRetryAfter(resp.Header.Get("Retry-After")), fmt.Errorf("receiver is rate limiting (429)") + } + if resp.StatusCode >= 500 { + return 0, fmt.Errorf("receiver returned status %d", resp.StatusCode) + } + return 0, &permanentDeliveryError{status: resp.StatusCode} +} + +// backoff returns the delay before the given retry attempt (1-based), growing +// exponentially with full jitter applied. Jitter matters because every replica +// retries against the same receiver after a shared outage; without it they would +// reconverge into a synchronized thundering herd on the first recovery. +func (s *httpSink) backoff(attempt int) time.Duration { + base := s.cfg.RetryBackoff + if base <= 0 { + base = time.Second + } + // Cap the exponent so a large max_retries cannot overflow the shift. + shift := attempt - 1 + if shift > 10 { + shift = 10 + } + delay := base << shift + if half := delay / 2; half > 0 { + delay = half + time.Duration(rand.Int64N(int64(half))) + } + return delay +} + +// sleep waits for d, returning false if shutdown was requested first so the caller +// stops retrying instead of holding shutdown open for the full backoff. +func (s *httpSink) sleep(d time.Duration) bool { + if d <= 0 { + return true + } + t := time.NewTimer(d) + defer t.Stop() + select { + case <-t.C: + return true + case <-s.done: + return false + } +} + +// Close stops the sender goroutine after a final flush, bounded by ctx. Safe to +// call more than once. +func (s *httpSink) Close(ctx context.Context) error { + s.closeOnce.Do(func() { close(s.done) }) + select { + case <-s.stopped: + return nil + case <-ctx.Done(): + return fmt.Errorf("traffic-log HTTP sink did not finish flushing: %w", ctx.Err()) + } +} + +// encodeNDJSON joins the batch into a newline-delimited body. Each element is +// already a complete JSON object produced by the Log publisher. +// +// This shape is accepted directly by Splunk HEC's /services/collector/raw, +// Elasticsearch and OpenSearch _bulk, Grafana Loki via its OTLP/JSON push path, +// Fluent Bit's http input, and the OpenTelemetry Collector, so no receiver-specific +// envelope is needed for any of them. +func encodeNDJSON(batch [][]byte) []byte { + total := 0 + for _, line := range batch { + total += len(line) + 1 + } + buf := bytes.NewBuffer(make([]byte, 0, total)) + for _, line := range batch { + buf.Write(line) + buf.WriteByte('\n') + } + return buf.Bytes() +} + +// parseRetryAfter interprets a Retry-After header in either delta-seconds or +// HTTP-date form, clamped to retryAfterCap. Anything unparseable yields 0, which +// leaves the caller on its own backoff. +func parseRetryAfter(v string) time.Duration { + v = strings.TrimSpace(v) + if v == "" { + return 0 + } + if secs, err := strconv.Atoi(v); err == nil { + if secs < 0 { + return 0 + } + // Clamp BEFORE converting: time.Duration(secs) * time.Second overflows + // int64 for a large Retry-After and wraps negative, which would then slip + // past capDuration's upper bound and skip the wait entirely — turning a + // receiver's request to back off into an immediate retry. + if maxSecs := int(retryAfterCap / time.Second); secs > maxSecs { + return retryAfterCap + } + return capDuration(time.Duration(secs) * time.Second) + } + if t, err := http.ParseTime(v); err == nil { + if d := time.Until(t); d > 0 { + return capDuration(d) + } + } + return 0 +} + +func capDuration(d time.Duration) time.Duration { + if d > retryAfterCap { + return retryAfterCap + } + if d < 0 { + // Defence in depth against an overflowed conversion reaching here. + return 0 + } + return d +} + +// buildTrafficLogAuthHeader resolves the configured authentication into a single +// header name/value pair. Returns empty strings when no authentication is +// configured. Error messages never include the secret material. +func buildTrafficLogAuthHeader(cfg config.TrafficLogHTTPAuthConfig) (string, string, error) { + switch strings.ToLower(strings.TrimSpace(cfg.Type)) { + case "", config.TrafficLogAuthNone: + return "", "", nil + case config.TrafficLogAuthBearer: + if cfg.Bearer.Token == "" { + return "", "", fmt.Errorf("auth: bearer.token is required when type is %q", + config.TrafficLogAuthBearer) + } + return "Authorization", "Bearer " + cfg.Bearer.Token, nil + case config.TrafficLogAuthBasic: + if cfg.Basic.Username == "" || cfg.Basic.Password == "" { + return "", "", fmt.Errorf("auth: basic.username and basic.password are both required when type is %q", + config.TrafficLogAuthBasic) + } + // Reuse net/http's own encoding so the header matches what a server expects. + req := &http.Request{Header: http.Header{}} + req.SetBasicAuth(cfg.Basic.Username, cfg.Basic.Password) + return "Authorization", req.Header.Get("Authorization"), nil + case config.TrafficLogAuthHeader: + if cfg.Header.Name == "" || cfg.Header.Value == "" { + return "", "", fmt.Errorf("auth: header.name and header.value are both required when type is %q", + config.TrafficLogAuthHeader) + } + return cfg.Header.Name, cfg.Header.Value, nil + default: + return "", "", fmt.Errorf("auth: unknown type %q", cfg.Type) + } +} + +// buildTrafficLogTLSConfig assembles the client TLS configuration. +// +// X25519MLKEM768 is listed first in CurvePreferences per the repository's +// post-quantum standard: the traffic log carries request and response bodies, which +// is exactly the long-lived-confidentiality content a harvest-now-decrypt-later +// adversary would target. X25519 remains as the classical leg of that hybrid. +func buildTrafficLogTLSConfig(cfg config.TrafficLogHTTPTLSConfig) (*tls.Config, error) { + out := &tls.Config{ + MinVersion: tls.VersionTLS12, + CurvePreferences: []tls.CurveID{tls.X25519MLKEM768, tls.X25519}, + InsecureSkipVerify: cfg.InsecureSkipVerify, // #nosec G402 -- off by default; opt-in warns at startup + } + + if cfg.CAFile != "" { + pem, err := os.ReadFile(cfg.CAFile) + if err != nil { + return nil, fmt.Errorf("tls: cannot read ca_file %q: %w", cfg.CAFile, err) + } + pool := x509.NewCertPool() + if !pool.AppendCertsFromPEM(pem) { + return nil, fmt.Errorf("tls: ca_file %q contains no usable PEM certificate", cfg.CAFile) + } + out.RootCAs = pool + } + + if (cfg.CertFile == "") != (cfg.KeyFile == "") { + return nil, fmt.Errorf("tls: cert_file and key_file must be set together for mTLS") + } + if cfg.CertFile != "" { + pair, err := tls.LoadX509KeyPair(cfg.CertFile, cfg.KeyFile) + if err != nil { + return nil, fmt.Errorf("tls: cannot load client certificate/key pair: %w", err) + } + out.Certificates = []tls.Certificate{pair} + } + return out, nil +} diff --git a/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http_test.go b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http_test.go new file mode 100644 index 0000000000..0a863f26bb --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/analytics/publishers/sink_http_test.go @@ -0,0 +1,828 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package publishers + +import ( + "context" + "crypto/ecdsa" + "crypto/elliptic" + "crypto/rand" + "crypto/tls" + "crypto/x509" + "crypto/x509/pkix" + "encoding/pem" + "fmt" + "io" + "math/big" + "net" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "strings" + "sync" + "sync/atomic" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/config" + "github.com/wso2/api-platform/gateway/gateway-runtime/policy-engine/internal/metrics" +) + +// receiver is a stub log platform: it records every batch body and header set, and +// answers with a status the test controls. +type receiver struct { + mu sync.Mutex + bodies []string + headers []http.Header + status int + attempts int + // statusSeq, when non-empty, supplies a status per attempt, letting a test + // drive a failure-then-recovery sequence. + statusSeq []int + retryAfter string +} + +func (r *receiver) ServeHTTP(w http.ResponseWriter, req *http.Request) { + body, _ := io.ReadAll(req.Body) + + r.mu.Lock() + r.bodies = append(r.bodies, string(body)) + r.headers = append(r.headers, req.Header.Clone()) + status := r.status + if len(r.statusSeq) > 0 { + if r.attempts < len(r.statusSeq) { + status = r.statusSeq[r.attempts] + } else { + status = r.statusSeq[len(r.statusSeq)-1] + } + } + r.attempts++ + retryAfter := r.retryAfter + r.mu.Unlock() + + if retryAfter != "" { + w.Header().Set("Retry-After", retryAfter) + } + w.WriteHeader(status) +} + +func (r *receiver) snapshot() ([]string, []http.Header, int) { + r.mu.Lock() + defer r.mu.Unlock() + return append([]string(nil), r.bodies...), append([]http.Header(nil), r.headers...), r.attempts +} + +func httpSinkCfg(endpoint string) config.TrafficLogHTTPConfig { + cfg := config.TrafficLogHTTPConfig{ + Endpoint: endpoint, + ContentType: "application/x-ndjson", + AllowInsecureTransport: true, + BatchMaxEvents: 100, + BatchMaxBytes: 1 << 20, + FlushInterval: 25 * time.Millisecond, + QueueCapacity: 100, + OnQueueFull: config.TrafficLogQueueDropNew, + RequestTimeout: 2 * time.Second, + MaxRetries: 0, + RetryBackoff: time.Millisecond, + // Mirror the shipped default. A struct literal leaves this at Go's zero, + // which is honoured literally as "always abandon retries" — so without it + // every retry test would silently exercise a no-retry sink. + RetryAbortQueueRatio: config.DefaultTrafficLogRetryAbortQueueRatio, + Auth: config.TrafficLogHTTPAuthConfig{Type: config.TrafficLogAuthNone}, + } + return cfg +} + +// eventually polls cond until it holds or the deadline passes, so tests never +// depend on a fixed sleep matching the flush interval. +func eventually(t *testing.T, timeout time.Duration, cond func() bool) { + t.Helper() + deadline := time.Now().Add(timeout) + for time.Now().Before(deadline) { + if cond() { + return + } + time.Sleep(5 * time.Millisecond) + } + t.Fatalf("condition not met within %s", timeout) +} + +func TestHTTPSink_DeliversNDJSONBatch(t *testing.T) { + rec := &receiver{status: http.StatusOK} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + s, err := newHTTPSink(httpSinkCfg(srv.URL)) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + s.Write([]byte(`{"n":2}`)) + + eventually(t, 2*time.Second, func() bool { + bodies, _, _ := rec.snapshot() + return len(bodies) > 0 + }) + + bodies, headers, _ := rec.snapshot() + joined := strings.Join(bodies, "") + assert.Contains(t, joined, `{"n":1}`) + assert.Contains(t, joined, `{"n":2}`) + assert.True(t, strings.HasSuffix(bodies[0], "\n"), "NDJSON body must be newline terminated") + assert.Equal(t, "application/x-ndjson", headers[0].Get("Content-Type")) + assert.Equal(t, config.TrafficLogSinkHTTP, s.Name()) +} + +// Splunk HEC uses "Authorization: Splunk ", which the bearer type cannot +// express — this is why the header auth type exists. +func TestHTTPSink_AuthHeaderVariants(t *testing.T) { + cases := map[string]struct { + auth config.TrafficLogHTTPAuthConfig + name string + want string + // absent names a header that must NOT be on the request. + absent string + }{ + "bearer": { + auth: config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthBearer, + Bearer: config.TrafficLogHTTPAuthBearerConfig{Token: "abc"}, + }, + name: "Authorization", want: "Bearer abc", + }, + "splunk hec via header": { + auth: config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthHeader, + Header: config.TrafficLogHTTPAuthHeaderConfig{Name: "Authorization", Value: "Splunk deadbeef"}, + }, + name: "Authorization", want: "Splunk deadbeef", + }, + "non-authorization header": { + auth: config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthHeader, + Header: config.TrafficLogHTTPAuthHeaderConfig{Name: "X-API-Key", Value: "k-1"}, + }, + name: "X-API-Key", want: "k-1", + }, + "basic": { + auth: config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthBasic, + Basic: config.TrafficLogHTTPAuthBasicConfig{Username: "u", Password: "p"}, + }, + name: "Authorization", want: "Basic dTpw", + }, + // A populated sub-table for a type that was not selected must not leak + // onto the request — the selected type is the only thing consulted. + "unselected sub-tables are ignored": { + auth: config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthBearer, + Bearer: config.TrafficLogHTTPAuthBearerConfig{Token: "abc"}, + Basic: config.TrafficLogHTTPAuthBasicConfig{Username: "u", Password: "p"}, + Header: config.TrafficLogHTTPAuthHeaderConfig{Name: "X-API-Key", Value: "k-1"}, + }, + name: "Authorization", want: "Bearer abc", absent: "X-API-Key", + }, + } + for name, tc := range cases { + t.Run(name, func(t *testing.T) { + rec := &receiver{status: http.StatusOK} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.Auth = tc.auth + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 2*time.Second, func() bool { + _, headers, _ := rec.snapshot() + return len(headers) > 0 + }) + + _, headers, _ := rec.snapshot() + assert.Equal(t, tc.want, headers[0].Get(tc.name)) + if tc.absent != "" { + assert.Empty(t, headers[0].Get(tc.absent), + "a sub-table for an unselected type must not reach the request") + } + }) + } +} + +func TestHTTPSink_RetriesServerErrorsThenSucceeds(t *testing.T) { + rec := &receiver{statusSeq: []int{500, 500, 200}} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.MaxRetries = 3 + cfg.RetryBackoff = time.Millisecond + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 3*time.Second, func() bool { + _, _, attempts := rec.snapshot() + return attempts >= 3 + }) +} + +// A 4xx means the receiver rejected the batch's shape. Retrying cannot help and +// would only amplify a permanent failure. +func TestHTTPSink_DoesNotRetryClientErrors(t *testing.T) { + rec := &receiver{status: http.StatusBadRequest} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.MaxRetries = 5 + cfg.RetryBackoff = time.Millisecond + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 2*time.Second, func() bool { + _, _, attempts := rec.snapshot() + return attempts >= 1 + }) + time.Sleep(200 * time.Millisecond) // any retry would land well inside this + + _, _, attempts := rec.snapshot() + assert.Equal(t, 1, attempts, "a 400 must not be retried") +} + +func TestHTTPSink_HonoursRetryAfterOn429(t *testing.T) { + rec := &receiver{statusSeq: []int{http.StatusTooManyRequests, http.StatusOK}, retryAfter: "1"} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.MaxRetries = 2 + cfg.RetryBackoff = time.Millisecond + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + start := time.Now() + s.Write([]byte(`{"n":1}`)) + eventually(t, 5*time.Second, func() bool { + _, _, attempts := rec.snapshot() + return attempts >= 2 + }) + assert.GreaterOrEqual(t, time.Since(start), time.Second, + "the receiver's Retry-After must be honoured before the second attempt") +} + +// Write runs on the ALS ingest path. Blocking there backpressures Envoy, so a full +// queue must drop and return immediately. +func TestHTTPSink_WriteNeverBlocksOnFullQueue(t *testing.T) { + // A receiver that never answers keeps the sender goroutine busy, so the queue + // fills and stays full. + block := make(chan struct{}) + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + <-block + })) + t.Cleanup(func() { close(block); srv.Close() }) + + cfg := httpSinkCfg(srv.URL) + cfg.QueueCapacity = 4 + cfg.FlushInterval = time.Hour // only the size bound can trigger a flush + cfg.BatchMaxEvents = 1 + cfg.RequestTimeout = 5 * time.Second + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + done := make(chan struct{}) + go func() { + defer close(done) + for i := 0; i < 500; i++ { + s.Write([]byte(fmt.Sprintf(`{"i":%d}`, i))) + } + }() + + select { + case <-done: + case <-time.After(3 * time.Second): + t.Fatal("Write blocked on a full queue; it must drop and return immediately") + } +} + +// Nothing may reach stdout when delivery fails: that is what putting bodies back in +// the container log would look like. +func TestHTTPSink_UnreachableEndpointDropsWithoutFallback(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {})) + endpoint := srv.URL + srv.Close() // now refusing connections + + cfg := httpSinkCfg(endpoint) + cfg.MaxRetries = 1 + cfg.RetryBackoff = time.Millisecond + s, err := newHTTPSink(cfg) + require.NoError(t, err) + + s.Write([]byte(`{"secret":"value"}`)) + require.NoError(t, s.Close(context.Background())) + // No assertion on stdout is possible here without capturing the process's fd; + // the guarantee is structural — httpSink holds no writer other than its HTTP + // client, so there is no code path from a delivery failure to stdout. +} + +// A graceful shutdown must deliver what was accepted but not yet sent. +func TestHTTPSink_CloseFlushesPendingBatch(t *testing.T) { + rec := &receiver{status: http.StatusOK} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.FlushInterval = time.Hour // nothing would be sent without the shutdown flush + s, err := newHTTPSink(cfg) + require.NoError(t, err) + + s.Write([]byte(`{"pending":true}`)) + require.NoError(t, s.Close(context.Background())) + + bodies, _, _ := rec.snapshot() + require.Len(t, bodies, 1, "the pending batch must be delivered during Close") + assert.Contains(t, bodies[0], `{"pending":true}`) +} + +func TestHTTPSink_CloseIsIdempotent(t *testing.T) { + rec := &receiver{status: http.StatusOK} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + s, err := newHTTPSink(httpSinkCfg(srv.URL)) + require.NoError(t, err) + require.NoError(t, s.Close(context.Background())) + require.NoError(t, s.Close(context.Background())) +} + +// Close must not hang when the receiver does: shutdown is bounded by the caller's +// context. +func TestHTTPSink_CloseRespectsContextDeadline(t *testing.T) { + block := make(chan struct{}) + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + <-block + })) + t.Cleanup(func() { close(block); srv.Close() }) + + cfg := httpSinkCfg(srv.URL) + cfg.RequestTimeout = 30 * time.Second + cfg.BatchMaxEvents = 1 + cfg.FlushInterval = 10 * time.Millisecond + s, err := newHTTPSink(cfg) + require.NoError(t, err) + + s.Write([]byte(`{"n":1}`)) + time.Sleep(100 * time.Millisecond) // let the sender pick it up and stall + + ctx, cancel := context.WithTimeout(context.Background(), 200*time.Millisecond) + defer cancel() + start := time.Now() + err = s.Close(ctx) + assert.Error(t, err, "Close must report that the flush did not finish") + assert.Less(t, time.Since(start), 3*time.Second, "Close must not wait past its deadline") +} + +func TestHTTPSink_RejectsBadAuthAndTLSConfig(t *testing.T) { + t.Run("bearer without token", func(t *testing.T) { + cfg := httpSinkCfg("http://127.0.0.1:1") + cfg.Auth = config.TrafficLogHTTPAuthConfig{Type: config.TrafficLogAuthBearer} + _, err := newHTTPSink(cfg) + assert.Error(t, err) + }) + t.Run("header without name", func(t *testing.T) { + cfg := httpSinkCfg("http://127.0.0.1:1") + cfg.Auth = config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthHeader, + Header: config.TrafficLogHTTPAuthHeaderConfig{Value: "x"}, + } + _, err := newHTTPSink(cfg) + assert.Error(t, err) + }) + t.Run("half-configured mTLS", func(t *testing.T) { + cfg := httpSinkCfg("http://127.0.0.1:1") + cfg.TLS = config.TrafficLogHTTPTLSConfig{CertFile: "/nonexistent.pem"} + _, err := newHTTPSink(cfg) + assert.Error(t, err) + }) + t.Run("unreadable ca file", func(t *testing.T) { + cfg := httpSinkCfg("http://127.0.0.1:1") + cfg.TLS = config.TrafficLogHTTPTLSConfig{CAFile: "/nonexistent-ca.pem"} + _, err := newHTTPSink(cfg) + assert.Error(t, err) + }) +} + +func TestParseRetryAfter(t *testing.T) { + assert.Equal(t, 5*time.Second, parseRetryAfter("5")) + assert.Equal(t, time.Duration(0), parseRetryAfter("")) + assert.Equal(t, time.Duration(0), parseRetryAfter("not-a-number")) + assert.Equal(t, time.Duration(0), parseRetryAfter("-3")) + assert.Equal(t, retryAfterCap, parseRetryAfter("99999"), "a huge Retry-After must be capped") +} + +func TestEncodeNDJSON(t *testing.T) { + got := encodeNDJSON([][]byte{[]byte(`{"a":1}`), []byte(`{"b":2}`)}) + assert.Equal(t, "{\"a\":1}\n{\"b\":2}\n", string(got)) +} + +// Jitter is what keeps replicas from reconverging into a thundering herd after a +// shared receiver outage, so successive backoffs must not all be identical. +func TestHTTPSink_BackoffIsJitteredAndGrows(t *testing.T) { + s := &httpSink{cfg: config.TrafficLogHTTPConfig{RetryBackoff: time.Second}} + + seen := map[time.Duration]bool{} + for i := 0; i < 20; i++ { + d := s.backoff(1) + assert.GreaterOrEqual(t, d, 500*time.Millisecond) + assert.LessOrEqual(t, d, time.Second) + seen[d] = true + } + assert.Greater(t, len(seen), 1, "backoff must be jittered, not a fixed delay") + + assert.Greater(t, s.backoff(3), 500*time.Millisecond) + assert.LessOrEqual(t, s.backoff(3), 4*time.Second) +} + +// --- mTLS ------------------------------------------------------------------- +// +// Test certificates use ECDSA P-256, matching internal/utils/grpc_test.go. That +// is not a post-quantum-cryptography.md violation: X.509 certificates cannot be +// ML-DSA-signed in Go's TLS stack today, and the key exchange these tests +// actually exercise is the hybrid X25519MLKEM768 that buildTrafficLogTLSConfig +// puts first in CurvePreferences. + +// tlsFixture is a throwaway CA plus a server and client leaf signed by it, +// written to PEM files the sink config can reference by path. +type tlsFixture struct { + caFile, serverCert, serverKey, clientCert, clientKey string + caPool *x509.CertPool + serverPair tls.Certificate +} + +func newTLSFixture(t *testing.T) *tlsFixture { + t.Helper() + dir := t.TempDir() + + caKey, err := ecdsa.GenerateKey(elliptic.P256(), rand.Reader) + require.NoError(t, err) + caTmpl := &x509.Certificate{ + SerialNumber: big.NewInt(1), + Subject: pkix.Name{CommonName: "traffic-log-test-ca"}, + NotBefore: time.Now().Add(-time.Hour), + NotAfter: time.Now().Add(time.Hour), + IsCA: true, + KeyUsage: x509.KeyUsageCertSign | x509.KeyUsageDigitalSignature, + BasicConstraintsValid: true, + } + caDER, err := x509.CreateCertificate(rand.Reader, caTmpl, caTmpl, &caKey.PublicKey, caKey) + require.NoError(t, err) + caCert, err := x509.ParseCertificate(caDER) + require.NoError(t, err) + + leaf := func(cn string, serial int64, server bool) (string, string) { + key, err := ecdsa.GenerateKey(elliptic.P256(), rand.Reader) + require.NoError(t, err) + tmpl := &x509.Certificate{ + SerialNumber: big.NewInt(serial), + Subject: pkix.Name{CommonName: cn}, + NotBefore: time.Now().Add(-time.Hour), + NotAfter: time.Now().Add(time.Hour), + KeyUsage: x509.KeyUsageDigitalSignature, + } + if server { + tmpl.ExtKeyUsage = []x509.ExtKeyUsage{x509.ExtKeyUsageServerAuth} + tmpl.DNSNames = []string{"localhost"} + tmpl.IPAddresses = []net.IP{net.ParseIP("127.0.0.1")} + } else { + tmpl.ExtKeyUsage = []x509.ExtKeyUsage{x509.ExtKeyUsageClientAuth} + } + der, err := x509.CreateCertificate(rand.Reader, tmpl, caCert, &key.PublicKey, caKey) + require.NoError(t, err) + keyDER, err := x509.MarshalECPrivateKey(key) + require.NoError(t, err) + + certPath := filepath.Join(dir, cn+".crt") + keyPath := filepath.Join(dir, cn+".key") + require.NoError(t, os.WriteFile(certPath, + pem.EncodeToMemory(&pem.Block{Type: "CERTIFICATE", Bytes: der}), 0o600)) + require.NoError(t, os.WriteFile(keyPath, + pem.EncodeToMemory(&pem.Block{Type: "EC PRIVATE KEY", Bytes: keyDER}), 0o600)) + return certPath, keyPath + } + + caPath := filepath.Join(dir, "ca.crt") + require.NoError(t, os.WriteFile(caPath, + pem.EncodeToMemory(&pem.Block{Type: "CERTIFICATE", Bytes: caDER}), 0o600)) + + f := &tlsFixture{caFile: caPath} + f.serverCert, f.serverKey = leaf("server", 2, true) + f.clientCert, f.clientKey = leaf("client", 3, false) + + f.caPool = x509.NewCertPool() + require.True(t, f.caPool.AppendCertsFromPEM(pem.EncodeToMemory( + &pem.Block{Type: "CERTIFICATE", Bytes: caDER}))) + f.serverPair, err = tls.LoadX509KeyPair(f.serverCert, f.serverKey) + require.NoError(t, err) + return f +} + +// mtlsServer starts a TLS receiver that REQUIRES and verifies a client certificate. +func (f *tlsFixture) mtlsServer(t *testing.T, rec *receiver) *httptest.Server { + t.Helper() + srv := httptest.NewUnstartedServer(rec) + srv.TLS = &tls.Config{ + MinVersion: tls.VersionTLS12, + Certificates: []tls.Certificate{f.serverPair}, + ClientAuth: tls.RequireAndVerifyClientCert, + ClientCAs: f.caPool, + } + srv.StartTLS() + t.Cleanup(srv.Close) + return srv +} + +// TestHTTPSink_MutualTLS proves the client certificate is actually presented and +// accepted — the existing TLS test only covers rejecting a half-configured pair. +func TestHTTPSink_MutualTLS(t *testing.T) { + f := newTLSFixture(t) + rec := &receiver{status: http.StatusOK} + srv := f.mtlsServer(t, rec) + + cfg := httpSinkCfg(srv.URL) + cfg.AllowInsecureTransport = false // a real https:// endpoint + cfg.TLS = config.TrafficLogHTTPTLSConfig{ + CAFile: f.caFile, + CertFile: f.clientCert, + KeyFile: f.clientKey, + } + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 3*time.Second, func() bool { + bodies, _, _ := rec.snapshot() + return len(bodies) > 0 + }) + bodies, _, _ := rec.snapshot() + assert.Contains(t, bodies[0], `{"n":1}`, + "the batch must arrive over a mutually-authenticated connection") +} + +// TestHTTPSink_MutualTLSComposesWithAuth pins the orthogonality the config shape +// implies: the client certificate authenticates the transport, the auth block +// authenticates the request, and selecting one does not disable the other. +func TestHTTPSink_MutualTLSComposesWithAuth(t *testing.T) { + f := newTLSFixture(t) + rec := &receiver{status: http.StatusOK} + srv := f.mtlsServer(t, rec) + + cfg := httpSinkCfg(srv.URL) + cfg.AllowInsecureTransport = false + cfg.TLS = config.TrafficLogHTTPTLSConfig{ + CAFile: f.caFile, CertFile: f.clientCert, KeyFile: f.clientKey, + } + cfg.Auth = config.TrafficLogHTTPAuthConfig{ + Type: config.TrafficLogAuthBearer, + Bearer: config.TrafficLogHTTPAuthBearerConfig{Token: "tok-abc"}, + } + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 3*time.Second, func() bool { + _, headers, _ := rec.snapshot() + return len(headers) > 0 + }) + _, headers, _ := rec.snapshot() + assert.Equal(t, "Bearer tok-abc", headers[0].Get("Authorization"), + "mTLS must not suppress the configured auth header") +} + +// TestHTTPSink_MutualTLSRequiredButNotConfigured is the fail-closed case: the +// receiver demands a client certificate and the sink has none, so the handshake +// fails, the line is dropped and counted, and nothing falls back to stdout. +func TestHTTPSink_MutualTLSRequiredButNotConfigured(t *testing.T) { + f := newTLSFixture(t) + rec := &receiver{status: http.StatusOK} + srv := f.mtlsServer(t, rec) + + cfg := httpSinkCfg(srv.URL) + cfg.AllowInsecureTransport = false + cfg.TLS = config.TrafficLogHTTPTLSConfig{CAFile: f.caFile} // trusts the CA, presents nothing + s, err := newHTTPSink(cfg) + require.NoError(t, err, "the sink still builds — the failure is at handshake time, not config time") + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + require.NoError(t, s.Close(context.Background())) + + bodies, _, _ := rec.snapshot() + assert.Empty(t, bodies, "no batch may reach a receiver that rejected the handshake") +} + +// TestHTTPSink_RetryAfterReplacesBackoff pins that a receiver-supplied +// Retry-After is used INSTEAD of the exponential backoff, not in addition to it. +// Sleeping both made "Retry-After: 2" wait 2s + the backoff, overshooting the +// delay the receiver actually asked for. +func TestHTTPSink_RetryAfterReplacesBackoff(t *testing.T) { + var mu sync.Mutex + var stamps []time.Time + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + mu.Lock() + stamps = append(stamps, time.Now()) + n := len(stamps) + mu.Unlock() + if n == 1 { + w.Header().Set("Retry-After", "1") + w.WriteHeader(http.StatusTooManyRequests) + return + } + w.WriteHeader(http.StatusOK) + })) + t.Cleanup(srv.Close) + + cfg := httpSinkCfg(srv.URL) + cfg.MaxRetries = 3 + cfg.RetryBackoff = 3 * time.Second // deliberately far larger than Retry-After + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + s.Write([]byte(`{"n":1}`)) + eventually(t, 8*time.Second, func() bool { + mu.Lock() + defer mu.Unlock() + return len(stamps) >= 2 + }) + + mu.Lock() + gap := stamps[1].Sub(stamps[0]) + mu.Unlock() + // Retry-After alone is 1s. Backoff alone (or both) would be >= 1.5s. + assert.Less(t, gap, 1500*time.Millisecond, + "Retry-After must replace the backoff, not stack with it (gap was %s)", gap) + assert.GreaterOrEqual(t, gap, 900*time.Millisecond, + "the receiver's Retry-After must still be honoured (gap was %s)", gap) +} + +// TestHTTPSink_WriteAfterCloseIsCounted pins that a line written after Close is +// accounted for. Previously it was accepted into the queue that no longer had a +// reader, so it was neither delivered nor counted — silent loss, the one outcome +// the drop counter exists to rule out. +func TestHTTPSink_WriteAfterCloseIsCounted(t *testing.T) { + rec := &receiver{status: http.StatusOK} + srv := httptest.NewServer(rec) + t.Cleanup(srv.Close) + + s, err := newHTTPSink(httpSinkCfg(srv.URL)) + require.NoError(t, err) + require.NoError(t, s.Close(context.Background())) + + before := gatherCounter(t, "policy_engine_traffic_log_dropped_total", "http") + for i := 0; i < 5; i++ { + s.Write([]byte(`{"after":"close"}`)) + } + after := gatherCounter(t, "policy_engine_traffic_log_dropped_total", "http") + + assert.Equal(t, float64(5), after-before, + "every line written after Close must be counted as dropped, not silently discarded") + bodies, _, _ := rec.snapshot() + assert.Empty(t, bodies, "nothing may be delivered after Close") +} + +// gatherCounter sums a counter across all label sets matching sink. +func gatherCounter(t *testing.T, name, sink string) float64 { + t.Helper() + families, err := metrics.GetRegistry().Gather() + require.NoError(t, err) + var total float64 + for _, f := range families { + if f.GetName() != name { + continue + } + for _, m := range f.GetMetric() { + for _, l := range m.GetLabel() { + if l.GetName() == "sink" && l.GetValue() == sink { + total += m.GetCounter().GetValue() + } + } + } + } + return total +} + +// TestHTTPSink_RejectsInvalidTuning pins CodeRabbit #5: the constructor is +// documented fail-closed, and a panic is not failing closed. A non-positive +// FlushInterval previously panicked inside time.NewTicker. +func TestHTTPSink_RejectsInvalidTuning(t *testing.T) { + cases := map[string]func(*config.TrafficLogHTTPConfig){ + "flush_interval": func(c *config.TrafficLogHTTPConfig) { c.FlushInterval = 0 }, + "request_timeout": func(c *config.TrafficLogHTTPConfig) { c.RequestTimeout = 0 }, + "queue_capacity": func(c *config.TrafficLogHTTPConfig) { c.QueueCapacity = -1 }, + "batch_max_events": func(c *config.TrafficLogHTTPConfig) { c.BatchMaxEvents = 0 }, + "batch_max_bytes": func(c *config.TrafficLogHTTPConfig) { c.BatchMaxBytes = 0 }, + "max_retries": func(c *config.TrafficLogHTTPConfig) { c.MaxRetries = -1 }, + } + for name, mutate := range cases { + t.Run(name, func(t *testing.T) { + cfg := httpSinkCfg("http://127.0.0.1:1") + mutate(&cfg) + s, err := newHTTPSink(cfg) // must return, never panic + if err == nil { + _ = s.Close(context.Background()) + } + require.Error(t, err) + assert.Contains(t, err.Error(), name) + }) + } +} + +// TestParseRetryAfter_ClampsOverflow pins CodeRabbit #6: time.Duration(secs) * +// time.Second overflows int64 for a huge Retry-After and wraps negative, which +// slipped past capDuration's upper bound and skipped the wait entirely — turning +// a request to back off into an immediate retry. +func TestParseRetryAfter_ClampsOverflow(t *testing.T) { + for _, v := range []string{"9223372036854775807", "10000000000", "999999999"} { + got := parseRetryAfter(v) + assert.GreaterOrEqual(t, got, time.Duration(0), "Retry-After %q must never be negative", v) + assert.LessOrEqual(t, got, retryAfterCap, "Retry-After %q must be capped", v) + } + assert.Equal(t, 5*time.Second, parseRetryAfter("5"), "an ordinary value is unchanged") +} + +// TestHTTPSink_AbandonsRetriesUnderQueuePressure pins the head-of-line fix. +// +// deliver runs inside the single sender goroutine, so a batch retrying against a +// receiver that accepts and never answers stops the queue draining for the whole +// retry budget — 43-47s with the defaults, up to ~130s on a 429 with a large +// Retry-After. At any real event rate that fills the queue, so retrying to save +// one batch costs far more newer events to queue_full. Past the high-water mark +// the batch must be abandoned so draining resumes. +func TestHTTPSink_AbandonsRetriesUnderQueuePressure(t *testing.T) { + var attempts int64 + block := make(chan struct{}) + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + atomic.AddInt64(&attempts, 1) + <-block // accept, never answer + })) + t.Cleanup(func() { close(block); srv.Close() }) + + cfg := httpSinkCfg(srv.URL) + cfg.RequestTimeout = 150 * time.Millisecond + cfg.RetryBackoff = 10 * time.Millisecond + cfg.MaxRetries = 5 + cfg.BatchMaxEvents = 2 + cfg.FlushInterval = 10 * time.Millisecond + cfg.QueueCapacity = 20 // abort threshold is 10 + s, err := newHTTPSink(cfg) + require.NoError(t, err) + t.Cleanup(func() { _ = s.Close(context.Background()) }) + + before := gatherCounter(t, "policy_engine_traffic_log_dropped_total", "http") + + // One batch to occupy the sender, then push enough to cross the threshold. + s.Write([]byte(`{"n":1}`)) + s.Write([]byte(`{"n":2}`)) + eventually(t, 2*time.Second, func() bool { return atomic.LoadInt64(&attempts) >= 1 }) + for i := 0; i < 15; i++ { + s.Write([]byte(`{"n":9}`)) + } + + // The stuck batch must be abandoned rather than consuming all 5 retries. + eventually(t, 5*time.Second, func() bool { + return gatherCounter(t, "policy_engine_traffic_log_dropped_total", "http") > before + }) + assert.Less(t, atomic.LoadInt64(&attempts), int64(6), + "retries must stop early under queue pressure, not run the full budget") + + // And the queue must actually drain again rather than stay pinned. + eventually(t, 5*time.Second, func() bool { return len(s.queue) < cfg.QueueCapacity }) +} diff --git a/gateway/gateway-runtime/policy-engine/internal/config/config.go b/gateway/gateway-runtime/policy-engine/internal/config/config.go index 7bb39ead3f..a59318c950 100644 --- a/gateway/gateway-runtime/policy-engine/internal/config/config.go +++ b/gateway/gateway-runtime/policy-engine/internal/config/config.go @@ -19,11 +19,16 @@ package config import ( + "crypto/tls" + "crypto/x509" "fmt" "log/slog" "math" "net/url" + "os" + "path/filepath" "strconv" + "strings" "time" "github.com/go-viper/mapstructure/v2" @@ -104,14 +109,69 @@ type AnalyticsPublishersConfig struct { Moesif MoesifPublisherConfig `koanf:"moesif"` } -// TrafficLoggingConfig holds configuration for the stdout traffic-logging feature, -// which writes each collected event to stdout as a JSON line. It is a consumer of -// the collector; enabling it implicitly activates the collector. There is a single -// mode: when Enabled, a stdout line is emitted for every request to every API, with -// no policy required — including requests denied by an auth policy short-circuit. +// Traffic-log sink names accepted in traffic_logging.outputs. +const ( + // TrafficLogSinkStdout writes each line to the process's stdout. This is the + // default and the historical behavior. + TrafficLogSinkStdout = "stdout" + // TrafficLogSinkFile appends each line to a local file, rotating at a size + // ceiling. Keeps request/response bodies out of the container log. + TrafficLogSinkFile = "file" + // TrafficLogSinkHTTP batches lines and POSTs them to an operator-named + // endpoint. Requires no co-located log collector. + TrafficLogSinkHTTP = "http" +) + +// Traffic-log HTTP auth types accepted in traffic_logging.http.auth.type. +const ( + // TrafficLogAuthNone sends no authentication material. + TrafficLogAuthNone = "none" + // TrafficLogAuthBearer sends "Authorization: Bearer ". + TrafficLogAuthBearer = "bearer" + // TrafficLogAuthBasic sends "Authorization: Basic ". + TrafficLogAuthBasic = "basic" + // TrafficLogAuthHeader sends an arbitrary header. Required for receivers + // whose scheme is not Bearer — Splunk HEC uses "Authorization: Splunk ". + TrafficLogAuthHeader = "header" +) + +// Behavior when the HTTP sink's queue is full (traffic_logging.http.on_queue_full). +const ( + // TrafficLogQueueDropNew discards the incoming line, preserving older ones. + TrafficLogQueueDropNew = "drop_new" + // TrafficLogQueueDropOldest evicts the oldest queued line to make room. + TrafficLogQueueDropOldest = "drop_oldest" +) + +// TrafficLoggingConfig holds configuration for the traffic-logging feature, which +// writes each collected event as a JSON line to one or more sinks. It is a consumer +// of the collector; enabling it implicitly activates the collector. There is a single +// mode: when Enabled, a line is emitted for every request to every API, with no +// policy required — including requests denied by an auth policy short-circuit. +// +// The line contains request/response bodies when the corresponding capture flags are +// on, so the choice of sink is a data-protection decision, not just a routing one: +// the default stdout sink puts those bodies in the container log, and therefore on +// the node's disk and into any node-level log collector. type TrafficLoggingConfig struct { - // Enabled turns stdout JSON traffic logging on. + // Enabled turns JSON traffic logging on. Enabled bool `koanf:"enabled"` + // Outputs names the sinks each line is written to. Valid entries are + // "stdout", "file" and "http" (see the TrafficLogSink* constants); order is + // irrelevant and duplicates are rejected. Unset or empty resolves to + // ["stdout"] with a warning, preserving the historical behavior exactly; an + // unknown name is rejected at startup. Only a typo can be mistaken for an + // intent that was not honoured, so only a typo fails — an empty list + // expresses no intent to keep bodies out of the container log. + Outputs []string `koanf:"outputs"` + // File configures the "file" sink. Only read when Outputs contains "file". + File TrafficLogFileConfig `koanf:"file"` + // HTTP configures the "http" sink. Only read when Outputs contains "http". + HTTP TrafficLogHTTPConfig `koanf:"http"` + // ShutdownTimeout bounds the flush of buffering sinks on SIGTERM. Only the + // HTTP sink buffers; the stdout and file sinks write straight to their fd and + // have nothing to flush. + ShutdownTimeout time.Duration `koanf:"shutdown_timeout"` // MaskedHeaders lists header names (case-insensitive) whose values are // redacted in the logged requestHeaders/responseHeaders. MaskedHeaders []string `koanf:"masked_headers"` @@ -145,6 +205,170 @@ type TrafficLoggingConfig struct { Properties map[string]string `koanf:"properties"` } +// TrafficLogFileConfig configures the "file" traffic-log sink +// ([traffic_logging.file]). +// +// The file holds request/response bodies, so it is created 0600 inside a 0700 +// directory, with both modes established at creation time rather than chmod'd +// afterwards. There is deliberately no file_mode knob: 0600 is the only defensible +// value for this content, and making it configurable only creates a way to get it +// wrong. +type TrafficLogFileConfig struct { + // Path is the absolute path of the live log file. Required when the "file" + // sink is selected. A relative path is rejected rather than resolved against + // the process's working directory, which is almost never what was meant. + Path string `koanf:"path"` + // MaxSizeMB is the size at which the live file is rotated. Rotation renames + // the live file to .1 (clobbering any previous backup) and reopens, so + // the worst-case on-disk total is 2 x MaxSizeMB. + // + // 0 disables rotation entirely. That is permitted — an operator mounting a + // dedicated, sized volume may want the volume to be the bound — but it is not + // the default and it logs a warning at startup, because stdout is bounded by + // the kubelet today and an unrotated file is not bounded by anything. + MaxSizeMB int `koanf:"max_size_mb"` +} + +// TrafficLogHTTPConfig configures the "http" traffic-log sink +// ([traffic_logging.http]): lines are queued, batched, and POSTed to an +// operator-named endpoint. This removes the need for any co-located log collector +// (sidecar or node-level agent) and keeps the bodies off the node's disk entirely. +// +// The endpoint is operator configuration, at the same trust tier as the rest of +// config.toml, so the dial-time private-IP guard that ssrf-prevention.md requires +// for request-derived URLs does not apply here — this is a destination the operator +// chose deliberately, and internal ones are the normal case. +type TrafficLogHTTPConfig struct { + // Endpoint is the absolute URL each batch is POSTed to. Required when the + // "http" sink is selected. Must be https:// unless AllowInsecureTransport is + // explicitly set. + Endpoint string `koanf:"endpoint"` + // ContentType is the Content-Type header sent with each batch. Defaults to + // application/x-ndjson, which matches the newline-delimited body this sink + // produces and is accepted by Splunk HEC's /raw endpoint, Elasticsearch and + // OpenSearch _bulk, Fluent Bit's http input, and the OTel collector. + ContentType string `koanf:"content_type"` + // AllowInsecureTransport permits a plaintext http:// endpoint. Off by default + // and intended only for a local collector on the pod network; the traffic log + // carries request/response bodies, so plaintext is a real disclosure. + AllowInsecureTransport bool `koanf:"allow_insecure_transport"` + + // BatchMaxEvents / BatchMaxBytes / FlushInterval close a batch on whichever + // bound is reached first. + BatchMaxEvents int `koanf:"batch_max_events"` + BatchMaxBytes int `koanf:"batch_max_bytes"` + FlushInterval time.Duration `koanf:"flush_interval"` + + // QueueCapacity bounds the in-memory queue between the access-log ingest path + // and the sending goroutine. It must be bounded: an unbounded queue in front + // of a bounded sender is just deferred unbounded memory growth, and these + // events carry bodies, so the growth is fast. + QueueCapacity int `koanf:"queue_capacity"` + // OnQueueFull selects what happens when the queue is full — "drop_new" + // (default, preserves older lines) or "drop_oldest" (preserves recency). + // Either way a line is dropped and counted; the sink never blocks the caller + // and never falls back to stdout. + OnQueueFull string `koanf:"on_queue_full"` + + // RequestTimeout bounds a single POST attempt. + RequestTimeout time.Duration `koanf:"request_timeout"` + // MaxRetries is the number of retry attempts after the initial one. Retries + // apply to transport errors, 5xx and 429 only; a 4xx means the receiver + // rejected the batch's shape and retrying would just amplify it. + MaxRetries int `koanf:"max_retries"` + // RetryBackoff is the base delay for exponential backoff. Jitter is applied + // per attempt so replicas retrying after a shared outage do not synchronize. + RetryBackoff time.Duration `koanf:"retry_backoff"` + // RetryAbortQueueRatio is the fraction of QueueCapacity at which a retrying + // batch abandons its remaining attempts so the single sender can resume + // draining. + // + // There is one sender and it retries synchronously, so nothing drains the + // queue while a batch waits. Retrying is free while the queue is shallow and + // expensive once it is filling, which is exactly what this ratio expresses. + // + // The value is used literally, never remapped: 0 means retries are always + // abandoned (one attempt per batch), and 1 means never abort early — the + // behaviour before this existed, where a hung receiver holds the sender for + // the whole retry budget. Omitting the key leaves the shipped 0.5 default, + // which is distinct from writing 0. See EffectiveRetryAbortDepth. + RetryAbortQueueRatio float64 `koanf:"retry_abort_queue_ratio"` + + // Auth configures per-request authentication material. + Auth TrafficLogHTTPAuthConfig `koanf:"auth"` + // TLS configures the transport's trust and client-certificate material. + TLS TrafficLogHTTPTLSConfig `koanf:"tls"` +} + +// TrafficLogHTTPAuthConfig configures authentication for the HTTP sink +// ([traffic_logging.http.auth]). +// +// Secret values should be supplied via the config interpolation tokens rather than +// inlined, e.g. token = '{{ file "/secrets/gateway-runtime/hec-token" }}' or +// '{{ env "TRAFFIC_LOG_TOKEN" }}'. Nothing in this struct is ever logged, including +// on a transport error. +// Type selects the scheme and each scheme's fields live in its own sub-table, the +// same discriminator-plus-named-section shape [analytics] uses for +// enabled_publishers / [analytics.publishers.moesif]. Keeping the fields separated +// means a field can never be read under a type it does not belong to, and adding a +// scheme later touches only its own struct. +type TrafficLogHTTPAuthConfig struct { + // Type selects the scheme: "none" (default), "bearer", "basic" or "header". + // Only the matching sub-table below is read; the others are ignored entirely. + Type string `koanf:"type"` + + // Bearer is read only when Type is "bearer" ([traffic_logging.http.auth.bearer]). + Bearer TrafficLogHTTPAuthBearerConfig `koanf:"bearer"` + // Basic is read only when Type is "basic" ([traffic_logging.http.auth.basic]). + Basic TrafficLogHTTPAuthBasicConfig `koanf:"basic"` + // Header is read only when Type is "header" ([traffic_logging.http.auth.header]). + Header TrafficLogHTTPAuthHeaderConfig `koanf:"header"` +} + +// TrafficLogHTTPAuthBearerConfig configures the "bearer" scheme +// ([traffic_logging.http.auth.bearer]), sending "Authorization: Bearer ". +type TrafficLogHTTPAuthBearerConfig struct { + // Token is required when the "bearer" type is selected. + Token string `koanf:"token"` +} + +// TrafficLogHTTPAuthBasicConfig configures the "basic" scheme +// ([traffic_logging.http.auth.basic]), sending +// "Authorization: Basic ". +type TrafficLogHTTPAuthBasicConfig struct { + // Username and Password are both required when the "basic" type is selected. + Username string `koanf:"username"` + Password string `koanf:"password"` +} + +// TrafficLogHTTPAuthHeaderConfig configures the "header" scheme +// ([traffic_logging.http.auth.header]), sending one literal header verbatim. +// +// This exists because not every receiver uses the Bearer scheme: Splunk HEC +// expects "Authorization: Splunk ", which "bearer" cannot express. It also +// covers receivers authenticating on a non-Authorization header entirely. +type TrafficLogHTTPAuthHeaderConfig struct { + // Name and Value are both required when the "header" type is selected. + Name string `koanf:"name"` + Value string `koanf:"value"` +} + +// TrafficLogHTTPTLSConfig configures TLS for the HTTP sink +// ([traffic_logging.http.tls]). +type TrafficLogHTTPTLSConfig struct { + // CAFile is a PEM bundle used to verify the receiver's certificate. Empty + // means the system trust store, which is correct for a public SaaS receiver + // and usually wrong for an internal collector with a private CA. + CAFile string `koanf:"ca_file"` + // CertFile / KeyFile enable mTLS. Both must be set, or neither. + CertFile string `koanf:"cert_file"` + KeyFile string `koanf:"key_file"` + // InsecureSkipVerify disables receiver certificate verification. Off by + // default; when on, startup logs a warning naming the endpoint, because this + // exposes request/response bodies to anyone who can intercept the connection. + InsecureSkipVerify bool `koanf:"insecure_skip_verify"` +} + // MoesifPublisherConfig holds Moesif-specific configuration type MoesifPublisherConfig struct { ApplicationID string `koanf:"application_id"` @@ -491,6 +715,45 @@ func defaultMaskedHeaders() []string { return []string{"authorization", "x-api-key", "x-jwt-assertion"} } +// defaultTrafficLogFileConfig returns the defaults for the "file" traffic-log sink. +// Path is intentionally empty: it is required only when the sink is selected, and a +// default path would create a file nobody asked for. +func defaultTrafficLogFileConfig() TrafficLogFileConfig { + return TrafficLogFileConfig{ + Path: "", + // 100 MiB live + 100 MiB backup = 200 MiB worst case, comfortably under a + // modest emptyDir sizeLimit while still holding a useful window of traffic. + MaxSizeMB: 100, + } +} + +// defaultTrafficLogHTTPConfig returns the defaults for the "http" traffic-log sink. +// Endpoint is intentionally empty: it is required only when the sink is selected. +func defaultTrafficLogHTTPConfig() TrafficLogHTTPConfig { + return TrafficLogHTTPConfig{ + Endpoint: "", + ContentType: "application/x-ndjson", + // 100 events / 1 MiB / 5s: small enough that a low-traffic gateway still + // delivers promptly, large enough that a busy one is not doing a POST per + // request. + BatchMaxEvents: 100, + BatchMaxBytes: 1 << 20, + FlushInterval: 5 * time.Second, + // 10k lines is roughly 100 MiB at the 10 KiB/line worst case — enough to + // ride out a short receiver blip without letting a long outage grow the + // heap without bound. + QueueCapacity: 10000, + OnQueueFull: TrafficLogQueueDropNew, + RequestTimeout: 10 * time.Second, + MaxRetries: 3, + RetryBackoff: time.Second, + // Half: retry freely while the queue is shallow, stop once it is filling. + RetryAbortQueueRatio: DefaultTrafficLogRetryAbortQueueRatio, + Auth: TrafficLogHTTPAuthConfig{Type: TrafficLogAuthNone}, + TLS: TrafficLogHTTPTLSConfig{}, + } +} + // defaultAccessLogsServiceConfig returns the default policy-engine ALS receiver tuning. // Shared by the collector (canonical) and the deprecated [analytics].access_logs_service // alias so a partial alias override migrates cleanly. @@ -569,7 +832,13 @@ func defaultConfig() *Config { Server: defaultAccessLogsServiceConfig(), }, TrafficLogging: TrafficLoggingConfig{ - Enabled: false, + Enabled: false, + // Default to stdout so an existing deployment that upgrades without + // touching its config keeps byte-identical behavior. + Outputs: []string{TrafficLogSinkStdout}, + File: defaultTrafficLogFileConfig(), + HTTP: defaultTrafficLogHTTPConfig(), + ShutdownTimeout: DefaultTrafficLogShutdownTimeout, MaskedHeaders: defaultMaskedHeaders(), MaxPayloadSize: 0, RequestHeaders: false, @@ -914,5 +1183,362 @@ func (c *Config) validateTrafficLoggingConfig() error { "traffic logging can only select among what the collector captured, so no response body will be logged") } + // A non-positive shutdown timeout is not a misconfiguration worth refusing to + // start over — it only means "do not wait for buffered sinks to flush", which + // is degraded but not a disclosure. It is clamped to the default at the point + // of use (see DefaultTrafficLogShutdownTimeout). Negative is still nonsense. + if tl.ShutdownTimeout < 0 { + return fmt.Errorf("traffic_logging.shutdown_timeout must not be negative, got %s", tl.ShutdownTimeout) + } + + // Validate the effective sink set, not each section in isolation: a sink that + // cannot be built must fail startup rather than silently leaving the operator + // on stdout, which would put request/response bodies back into the container + // log — the exact disclosure a file/http sink is configured to prevent. + outputs, err := NormalizeTrafficLogOutputs(tl.Outputs) + if err != nil { + return err + } + for _, out := range outputs { + switch out { + case TrafficLogSinkStdout: + // Nothing to validate; always available. + case TrafficLogSinkFile: + if err := validateTrafficLogFileConfig(tl.File); err != nil { + return fmt.Errorf("traffic_logging.file: %w", err) + } + case TrafficLogSinkHTTP: + if err := validateTrafficLogHTTPConfig(tl.HTTP); err != nil { + return fmt.Errorf("traffic_logging.http: %w", err) + } + } + } + + return nil +} + +// NormalizeTrafficLogOutputs lower-cases and trims the configured sink names, +// rejecting an unknown name or a duplicate. It is exported so the publisher layer +// builds its sinks from exactly the same normalized list that was validated here, +// rather than re-parsing the raw strings and possibly disagreeing. +// +// An unset or empty list resolves to ["stdout"], the historical behavior, with a +// warning. It is deliberately not an error: the case that must fail loudly is a +// name that was meant to select a sink and does not (a typo such as "flie"), which +// would otherwise leave an operator who asked for a file sink writing bodies to the +// container log. An empty list expresses no such intent and cannot be mistaken for +// one. +func NormalizeTrafficLogOutputs(outputs []string) ([]string, error) { + normalized := make([]string, 0, len(outputs)) + seen := make(map[string]bool, len(outputs)) + for _, raw := range outputs { + out := strings.ToLower(strings.TrimSpace(raw)) + if out == "" { + continue + } + switch out { + case TrafficLogSinkStdout, TrafficLogSinkFile, TrafficLogSinkHTTP: + default: + return nil, fmt.Errorf("unknown traffic_logging.outputs entry %q (valid: %s, %s, %s)", + raw, TrafficLogSinkStdout, TrafficLogSinkFile, TrafficLogSinkHTTP) + } + if seen[out] { + return nil, fmt.Errorf("traffic_logging.outputs lists %q more than once", out) + } + seen[out] = true + normalized = append(normalized, out) + } + if len(normalized) == 0 { + if len(outputs) > 0 { + // The operator wrote something that reduced to nothing (e.g. outputs = + // [""]); say so rather than silently substituting a default. + slog.Warn("traffic_logging.outputs contains no usable sink name; falling back to " + + TrafficLogSinkStdout) + } + return []string{TrafficLogSinkStdout}, nil + } + return normalized, nil +} + +// EffectiveRetryAbortDepth returns the queue depth at or above which a retrying +// batch gives up. The configured ratio is used literally — it is NOT remapped, so +// what an operator writes is what runs: +// +// 0 depth 0, which every queue length satisfies: retries are always +// abandoned, i.e. one delivery attempt per batch. +// 0 < r <= 1 depth = queue_capacity * r. +// +// An omitted key keeps the shipped default (see defaultTrafficLogHTTPConfig), +// because config.Load unmarshals over a pre-populated struct: absent leaves 0.5 +// in place, while an explicit 0 overwrites it. That is what makes "0 means 0" +// safe here — the two cases are genuinely distinguishable. +// +// The floor applies only to a NON-zero ratio, where a depth of 0 could only come +// from rounding a small ratio against a small queue and would silently mean +// something the operator did not ask for. +func (c TrafficLogHTTPConfig) EffectiveRetryAbortDepth() int { + depth := int(float64(c.QueueCapacity) * c.RetryAbortQueueRatio) + if depth < 1 && c.RetryAbortQueueRatio > 0 { + depth = 1 + } + return depth +} + +// DefaultTrafficLogRetryAbortQueueRatio is the fraction of the HTTP sink's queue +// at which a retrying batch gives up. Half is a deliberate midpoint: high enough +// that an ordinary blip still gets its full retry budget, low enough that a hung +// receiver cannot consume the whole queue before the sender resumes draining. +const DefaultTrafficLogRetryAbortQueueRatio = 0.5 + +// DefaultTrafficLogShutdownTimeout bounds the flush of buffering traffic-log sinks +// when traffic_logging.shutdown_timeout is unset or non-positive. +const DefaultTrafficLogShutdownTimeout = 5 * time.Second + +// EffectiveShutdownTimeout returns the shutdown timeout to actually use, applying +// the default when the configured value is unset or non-positive. This keeps a +// hand-built Config (tests, embedding callers) from ending up with a zero timeout +// that would skip the flush entirely. +func (t TrafficLoggingConfig) EffectiveShutdownTimeout() time.Duration { + if t.ShutdownTimeout <= 0 { + return DefaultTrafficLogShutdownTimeout + } + return t.ShutdownTimeout +} + +// validateTrafficLogFileConfig checks the file sink can actually be used, and +// proves it by creating the parent directory and opening the file. Doing the real +// I/O here — rather than deferring it to first write — means a permissions or +// mount problem surfaces as a clean startup failure instead of silently dropping +// traffic logs at runtime, once PII is already flowing. +func validateTrafficLogFileConfig(cfg TrafficLogFileConfig) error { + path, err := ResolveTrafficLogFilePath(cfg.Path) + if err != nil { + return err + } + if cfg.MaxSizeMB < 0 { + return fmt.Errorf("max_size_mb must be >= 0, got %d", cfg.MaxSizeMB) + } + if cfg.MaxSizeMB == 0 { + slog.Warn("traffic_logging.file.max_size_mb is 0: rotation is disabled and the traffic log "+ + "will grow until the volume is full. Set a size ceiling, or make sure the mounted volume "+ + "bounds it.", "path", path) + } + + // 0700 on the directory and 0600 on the file, established at creation. umask + // can only clear permission bits, never add them, so these modes hold under + // any umask; a post-hoc chmod would leave a window where the file is readable. + if err := os.MkdirAll(filepath.Dir(path), 0o700); err != nil { + return fmt.Errorf("cannot create directory for %q: %w", path, err) + } + f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o600) + if err != nil { + return fmt.Errorf("cannot open %q for append: %w", path, err) + } + permErr := VerifyTrafficLogPerms(f, path) + if err := f.Close(); err != nil { + return fmt.Errorf("cannot close %q: %w", path, err) + } + return permErr +} + +// TrafficLogPermMask is the set of permission bits that must be clear on the +// traffic-log file and its directory: anything readable by group or other. +const TrafficLogPermMask os.FileMode = 0o077 + +// VerifyTrafficLogPerms fails when the traffic-log file or its directory is more +// permissive than the modes this sink creates. +// +// MkdirAll and O_CREATE apply their mode only when they actually create; a path +// left behind by an earlier run, restored from a backup, or pre-created on a +// mounted volume silently keeps its old permissions. That file holds request and +// response bodies, so a world-readable one left over from before defeats the +// entire reason for choosing the file sink. +// +// The file is a hard failure, per GO-AUTH-018: it is the confidentiality +// boundary, and it fails rather than chmod'ing because the restrictive mode must +// be established at creation time — a chmod after the descriptor is open leaves a +// window in which the file is both populated and readable. +// +// The containing directory only warns. A 0600 file is unreadable regardless of +// its directory's mode, so a permissive directory is an integrity and +// defence-in-depth concern rather than a disclosure. It cannot be an error +// because the directory is frequently not ours: under Kubernetes an emptyDir +// mount point is created 0777 by the kubelet, so an operator who points +// file.path straight at the mount root would otherwise be unable to start at all. +func VerifyTrafficLogPerms(f *os.File, path string) error { + fi, err := f.Stat() + if err != nil { + return fmt.Errorf("cannot stat %q: %w", path, err) + } + if perm := fi.Mode().Perm(); perm&TrafficLogPermMask != 0 { + return fmt.Errorf("%q has permissions %#o, which allow group/other access to logged "+ + "request and response bodies; it already existed so it kept its previous mode. "+ + "Fix it with `chmod 600 %s` (or remove the file) and restart", path, perm, path) + } + + dir := filepath.Dir(path) + if di, err := os.Stat(dir); err == nil { + if perm := di.Mode().Perm(); perm&TrafficLogPermMask != 0 { + slog.Warn("traffic-log directory is group/other accessible; the log file itself is "+ + "0600 so its contents are not exposed, but consider placing the file in a "+ + "dedicated 0700 subdirectory of the mount rather than at its root", + "dir", dir, "mode", fmt.Sprintf("%#o", perm)) + } + } + return nil +} + +// ResolveTrafficLogFilePath validates and cleans a traffic-log file path. Exported +// so the file sink resolves the path identically to the way it was validated. +func ResolveTrafficLogFilePath(path string) (string, error) { + if strings.TrimSpace(path) == "" { + return "", fmt.Errorf("path is required when the %q sink is selected", TrafficLogSinkFile) + } + if strings.ContainsRune(path, 0) { + return "", fmt.Errorf("path must not contain a null byte") + } + if !filepath.IsAbs(path) { + // A relative path resolves against the process's working directory, which + // is an implementation detail of the image and almost never intended. + return "", fmt.Errorf("path must be absolute, got %q", path) + } + // filepath.Clean RESOLVES ".." rather than rejecting it, so + // "/var/log/wso2/../../etc/traffic.log" would silently become + // "/etc/traffic.log" — outside whatever volume the operator mounted for it, + // and past the chart's mount-containment check, which compares the + // un-normalized string. Reject the traversal instead of quietly relocating + // the file (file-access.md directive 1). + for _, segment := range strings.Split(path, string(filepath.Separator)) { + if segment == ".." { + return "", fmt.Errorf("path must not contain %q segments, got %q", "..", path) + } + } + return filepath.Clean(path), nil +} + +// validateTrafficLogHTTPConfig checks the HTTP sink's endpoint, bounds, auth and +// TLS material. Any secret material referenced here has already been resolved by +// the {{ file }} / {{ env }} interpolation pass, so a missing secret file fails +// before this point. +func validateTrafficLogHTTPConfig(cfg TrafficLogHTTPConfig) error { + if strings.TrimSpace(cfg.Endpoint) == "" { + return fmt.Errorf("endpoint is required when the %q sink is selected", TrafficLogSinkHTTP) + } + u, err := url.Parse(cfg.Endpoint) + if err != nil { + return fmt.Errorf("endpoint is not a valid URL: %w", err) + } + switch u.Scheme { + case "https": + case "http": + if !cfg.AllowInsecureTransport { + return fmt.Errorf("endpoint uses plaintext http:// but allow_insecure_transport is false; " + + "the traffic log carries request and response bodies, so set allow_insecure_transport = true " + + "only for a trusted local collector") + } + slog.Warn("traffic_logging.http endpoint is plaintext http://; request and response bodies "+ + "are transmitted unencrypted", "host", u.Host) + default: + return fmt.Errorf("endpoint scheme must be https (or http with allow_insecure_transport), got %q", u.Scheme) + } + if u.Host == "" { + return fmt.Errorf("endpoint must include a host, got %q", cfg.Endpoint) + } + + if cfg.BatchMaxEvents <= 0 { + return fmt.Errorf("batch_max_events must be positive, got %d", cfg.BatchMaxEvents) + } + if cfg.BatchMaxBytes <= 0 { + return fmt.Errorf("batch_max_bytes must be positive, got %d", cfg.BatchMaxBytes) + } + if cfg.FlushInterval <= 0 { + return fmt.Errorf("flush_interval must be positive, got %s", cfg.FlushInterval) + } + if cfg.QueueCapacity <= 0 { + return fmt.Errorf("queue_capacity must be positive, got %d; an unbounded queue in front of a "+ + "bounded sender is deferred unbounded memory growth", cfg.QueueCapacity) + } + switch strings.ToLower(strings.TrimSpace(cfg.OnQueueFull)) { + case TrafficLogQueueDropNew, TrafficLogQueueDropOldest: + default: + return fmt.Errorf("on_queue_full must be %q or %q, got %q", + TrafficLogQueueDropNew, TrafficLogQueueDropOldest, cfg.OnQueueFull) + } + if cfg.RequestTimeout <= 0 { + return fmt.Errorf("request_timeout must be positive, got %s", cfg.RequestTimeout) + } + if cfg.MaxRetries < 0 { + return fmt.Errorf("max_retries must be >= 0, got %d", cfg.MaxRetries) + } + if cfg.MaxRetries > 0 && cfg.RetryBackoff <= 0 { + return fmt.Errorf("retry_backoff must be positive when max_retries > 0, got %s", cfg.RetryBackoff) + } + if cfg.RetryAbortQueueRatio < 0 || cfg.RetryAbortQueueRatio > 1 { + return fmt.Errorf("retry_abort_queue_ratio must be between 0 and 1 "+ + "(0 = always abandon retries, 1 = never abort early), got %v", + cfg.RetryAbortQueueRatio) + } + + if err := validateTrafficLogHTTPAuth(cfg.Auth); err != nil { + return fmt.Errorf("auth: %w", err) + } + if err := validateTrafficLogHTTPTLS(cfg.TLS, u.Host); err != nil { + return fmt.Errorf("tls: %w", err) + } + return nil +} + +// validateTrafficLogHTTPAuth checks the auth type and that its required fields are +// present. Error messages never include the secret value itself. +func validateTrafficLogHTTPAuth(cfg TrafficLogHTTPAuthConfig) error { + switch strings.ToLower(strings.TrimSpace(cfg.Type)) { + case "", TrafficLogAuthNone: + return nil + case TrafficLogAuthBearer: + if cfg.Bearer.Token == "" { + return fmt.Errorf("bearer.token is required when type is %q", TrafficLogAuthBearer) + } + case TrafficLogAuthBasic: + if cfg.Basic.Username == "" || cfg.Basic.Password == "" { + return fmt.Errorf("basic.username and basic.password are both required when type is %q", + TrafficLogAuthBasic) + } + case TrafficLogAuthHeader: + if cfg.Header.Name == "" || cfg.Header.Value == "" { + return fmt.Errorf("header.name and header.value are both required when type is %q", + TrafficLogAuthHeader) + } + default: + return fmt.Errorf("unknown type %q (valid: %s, %s, %s, %s)", cfg.Type, + TrafficLogAuthNone, TrafficLogAuthBearer, TrafficLogAuthBasic, TrafficLogAuthHeader) + } + return nil +} + +// validateTrafficLogHTTPTLS checks that any referenced TLS material exists and +// parses, so a bad path fails at startup rather than on the first batch. +func validateTrafficLogHTTPTLS(cfg TrafficLogHTTPTLSConfig, host string) error { + if cfg.InsecureSkipVerify { + slog.Warn("traffic_logging.http.tls.insecure_skip_verify is true: the receiver's certificate "+ + "is not verified, so request and response bodies are exposed to anyone able to intercept "+ + "this connection", "host", host) + } + if cfg.CAFile != "" { + pem, err := os.ReadFile(cfg.CAFile) + if err != nil { + return fmt.Errorf("cannot read ca_file %q: %w", cfg.CAFile, err) + } + if !x509.NewCertPool().AppendCertsFromPEM(pem) { + return fmt.Errorf("ca_file %q contains no usable PEM certificate", cfg.CAFile) + } + } + if (cfg.CertFile == "") != (cfg.KeyFile == "") { + return fmt.Errorf("cert_file and key_file must be set together for mTLS (one is set, the other is not)") + } + if cfg.CertFile != "" { + if _, err := tls.LoadX509KeyPair(cfg.CertFile, cfg.KeyFile); err != nil { + return fmt.Errorf("cannot load client certificate/key pair: %w", err) + } + } return nil } diff --git a/gateway/gateway-runtime/policy-engine/internal/config/traffic_log_sinks_test.go b/gateway/gateway-runtime/policy-engine/internal/config/traffic_log_sinks_test.go new file mode 100644 index 0000000000..a84b280e1b --- /dev/null +++ b/gateway/gateway-runtime/policy-engine/internal/config/traffic_log_sinks_test.go @@ -0,0 +1,458 @@ +/* + * Copyright (c) 2026, WSO2 LLC. (http://www.wso2.org) All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package config + +import ( + "os" + "path/filepath" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// trafficLogConfig returns a Config with traffic logging enabled and the given +// sink settings applied, ready for Validate. +func trafficLogConfig(mutate func(*TrafficLoggingConfig)) *Config { + cfg := defaultConfig() + cfg.TrafficLogging.Enabled = true + mutate(&cfg.TrafficLogging) + return cfg +} + +func TestNormalizeTrafficLogOutputs(t *testing.T) { + t.Run("unset defaults to stdout", func(t *testing.T) { + got, err := NormalizeTrafficLogOutputs(nil) + require.NoError(t, err) + assert.Equal(t, []string{TrafficLogSinkStdout}, got) + }) + + t.Run("explicitly empty falls back to stdout", func(t *testing.T) { + got, err := NormalizeTrafficLogOutputs([]string{}) + require.NoError(t, err) + assert.Equal(t, []string{TrafficLogSinkStdout}, got) + }) + + t.Run("case and whitespace are normalized", func(t *testing.T) { + got, err := NormalizeTrafficLogOutputs([]string{" File ", "HTTP"}) + require.NoError(t, err) + assert.Equal(t, []string{TrafficLogSinkFile, TrafficLogSinkHTTP}, got) + }) + + // A typo must fail loudly: silently ignoring it would leave an operator who + // asked for a file sink writing request bodies to the container log. + t.Run("unknown name is an error", func(t *testing.T) { + _, err := NormalizeTrafficLogOutputs([]string{"flie"}) + require.Error(t, err) + assert.Contains(t, err.Error(), "flie") + }) + + t.Run("duplicate is an error", func(t *testing.T) { + _, err := NormalizeTrafficLogOutputs([]string{"file", "file"}) + assert.Error(t, err) + }) +} + +func TestValidate_TrafficLogFileSink(t *testing.T) { + t.Run("valid path passes and creates the file", func(t *testing.T) { + path := filepath.Join(t.TempDir(), "nested", "traffic.log") + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkFile} + tl.File = TrafficLogFileConfig{Path: path, MaxSizeMB: 10} + }) + require.NoError(t, cfg.Validate()) + + // Validation proves the sink works by actually opening it, so a + // permissions or mount problem surfaces at startup rather than at the + // first request, once PII is already flowing. + fi, err := os.Stat(path) + require.NoError(t, err) + assert.Equal(t, os.FileMode(0o600), fi.Mode().Perm()) + }) + + t.Run("missing path fails closed", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkFile} + }) + err := cfg.Validate() + require.Error(t, err) + assert.Contains(t, err.Error(), "traffic_logging.file") + }) + + t.Run("relative path fails closed", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkFile} + tl.File = TrafficLogFileConfig{Path: "relative/traffic.log"} + }) + assert.Error(t, cfg.Validate()) + }) + + t.Run("unwritable directory fails closed rather than degrading to stdout", func(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("running as root: permission checks do not apply") + } + dir := t.TempDir() + require.NoError(t, os.Chmod(dir, 0o500)) // read+execute, no write + t.Cleanup(func() { _ = os.Chmod(dir, 0o700) }) + + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkFile} + tl.File = TrafficLogFileConfig{Path: filepath.Join(dir, "sub", "traffic.log")} + }) + assert.Error(t, cfg.Validate()) + }) + + t.Run("negative max size is an error", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkFile} + tl.File = TrafficLogFileConfig{Path: filepath.Join(t.TempDir(), "t.log"), MaxSizeMB: -1} + }) + assert.Error(t, cfg.Validate()) + }) +} + +func TestValidate_TrafficLogHTTPSink(t *testing.T) { + base := func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkHTTP} + tl.HTTP = defaultTrafficLogHTTPConfig() + tl.HTTP.Endpoint = "https://splunk.example.com:8088/services/collector/raw" + } + + t.Run("https endpoint passes", func(t *testing.T) { + assert.NoError(t, trafficLogConfig(base).Validate()) + }) + + t.Run("missing endpoint fails closed", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.Endpoint = "" + }) + err := cfg.Validate() + require.Error(t, err) + assert.Contains(t, err.Error(), "traffic_logging.http") + }) + + // The traffic log carries request and response bodies, so plaintext must be a + // deliberate opt-in rather than something a typo can produce. + t.Run("plaintext http requires explicit opt-in", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.Endpoint = "http://collector.internal:8088/ingest" + }) + assert.Error(t, cfg.Validate()) + + cfg = trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.Endpoint = "http://collector.internal:8088/ingest" + tl.HTTP.AllowInsecureTransport = true + }) + assert.NoError(t, cfg.Validate()) + }) + + t.Run("non-http scheme is rejected", func(t *testing.T) { + for _, endpoint := range []string{"file:///etc/passwd", "gopher://x/1", "ftp://x/y"} { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.Endpoint = endpoint + }) + assert.Error(t, cfg.Validate(), "endpoint %q must be rejected", endpoint) + } + }) + + // An unbounded queue in front of a bounded sender is deferred unbounded memory + // growth, and these lines carry bodies. + t.Run("queue capacity must be bounded and positive", func(t *testing.T) { + for _, capacity := range []int{0, -1} { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.QueueCapacity = capacity + }) + assert.Error(t, cfg.Validate()) + } + }) + + t.Run("batch and timeout bounds must be positive", func(t *testing.T) { + mutators := map[string]func(*TrafficLoggingConfig){ + "batch_max_events": func(tl *TrafficLoggingConfig) { tl.HTTP.BatchMaxEvents = 0 }, + "batch_max_bytes": func(tl *TrafficLoggingConfig) { tl.HTTP.BatchMaxBytes = 0 }, + "flush_interval": func(tl *TrafficLoggingConfig) { tl.HTTP.FlushInterval = 0 }, + "request_timeout": func(tl *TrafficLoggingConfig) { tl.HTTP.RequestTimeout = 0 }, + "max_retries": func(tl *TrafficLoggingConfig) { tl.HTTP.MaxRetries = -1 }, + } + for name, mutate := range mutators { + t.Run(name, func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + mutate(tl) + }) + assert.Error(t, cfg.Validate()) + }) + } + }) + + t.Run("on_queue_full must be a known policy", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.OnQueueFull = "block" + }) + assert.Error(t, cfg.Validate()) + }) + + t.Run("auth type validation", func(t *testing.T) { + cases := map[string]struct { + auth TrafficLogHTTPAuthConfig + wantErr bool + }{ + "none": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthNone}, false}, + "bearer with token": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthBearer, + Bearer: TrafficLogHTTPAuthBearerConfig{Token: "t"}}, false}, + "bearer no token": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthBearer}, true}, + "basic complete": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthBasic, + Basic: TrafficLogHTTPAuthBasicConfig{Username: "u", Password: "p"}}, false}, + "basic missing pass": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthBasic, + Basic: TrafficLogHTTPAuthBasicConfig{Username: "u"}}, true}, + "header complete": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthHeader, + Header: TrafficLogHTTPAuthHeaderConfig{Name: "Authorization", Value: "Splunk x"}}, false}, + "header missing name": {TrafficLogHTTPAuthConfig{Type: TrafficLogAuthHeader, + Header: TrafficLogHTTPAuthHeaderConfig{Value: "Splunk x"}}, true}, + "unknown type": {TrafficLogHTTPAuthConfig{Type: "oauth2"}, true}, + + // The sub-table shape makes this expressible, and it must still fail: + // fields under a type that was not selected are never consulted. + "bearer token supplied under the wrong sub-table": {TrafficLogHTTPAuthConfig{ + Type: TrafficLogAuthBearer, + Basic: TrafficLogHTTPAuthBasicConfig{Username: "u", Password: "p"}, + }, true}, + } + for name, tc := range cases { + t.Run(name, func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.Auth = tc.auth + }) + if tc.wantErr { + assert.Error(t, cfg.Validate()) + } else { + assert.NoError(t, cfg.Validate()) + } + }) + } + }) + + t.Run("tls material must exist and be usable", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.TLS.CAFile = "/nonexistent/ca.pem" + }) + assert.Error(t, cfg.Validate()) + + garbage := filepath.Join(t.TempDir(), "ca.pem") + require.NoError(t, os.WriteFile(garbage, []byte("not a certificate"), 0o600)) + cfg = trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.TLS.CAFile = garbage + }) + assert.Error(t, cfg.Validate()) + }) + + t.Run("mTLS cert and key must be set together", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + base(tl) + tl.HTTP.TLS.CertFile = "/some/cert.pem" + }) + assert.Error(t, cfg.Validate()) + }) +} + +func TestValidate_TrafficLogOutputsInteraction(t *testing.T) { + t.Run("unknown sink name fails startup", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{"flie"} + }) + assert.Error(t, cfg.Validate()) + }) + + // Selecting stdout alongside file must validate both, but a broken file sink + // still fails: a partially usable set is not "good enough". + t.Run("broken file sink fails even when stdout is also selected", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkStdout, TrafficLogSinkFile} + tl.File = TrafficLogFileConfig{Path: "not-absolute.log"} + }) + assert.Error(t, cfg.Validate()) + }) + + // Sink config is only read for sinks that are actually selected, so a stale + // [traffic_logging.http] block left behind by a rollback cannot fail startup. + t.Run("unselected sink config is not validated", func(t *testing.T) { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkStdout} + tl.HTTP.Endpoint = "not a url at all" + tl.File.Path = "also-not-absolute" + }) + assert.NoError(t, cfg.Validate()) + }) + + t.Run("disabled traffic logging skips sink validation entirely", func(t *testing.T) { + cfg := defaultConfig() + cfg.TrafficLogging.Enabled = false + cfg.TrafficLogging.Outputs = []string{TrafficLogSinkFile} + cfg.TrafficLogging.File = TrafficLogFileConfig{Path: "relative.log"} + assert.NoError(t, cfg.Validate()) + }) +} + +func TestEffectiveShutdownTimeout(t *testing.T) { + assert.Equal(t, DefaultTrafficLogShutdownTimeout, + TrafficLoggingConfig{}.EffectiveShutdownTimeout(), + "an unset timeout must fall back to the default rather than skipping the flush") + assert.Equal(t, 9*time.Second, + TrafficLoggingConfig{ShutdownTimeout: 9 * time.Second}.EffectiveShutdownTimeout()) +} + +// TestShippedTemplateMatchesTrafficLogDefaults loads the config-template.toml we +// actually ship and asserts its [traffic_logging] sink values equal the code +// defaults. The template is the reference an operator reads before writing their +// own config, so a value that drifts from the code does not just go stale — it +// documents a number the gateway will not use. +func TestShippedTemplateMatchesTrafficLogDefaults(t *testing.T) { + cfg, err := Load(filepath.Join("..", "..", "..", "..", "configs", "config-template.toml")) + require.NoError(t, err, "the shipped config-template.toml must load and validate") + + tl := cfg.TrafficLogging + assert.Equal(t, []string{TrafficLogSinkStdout}, tl.Outputs, + "the template must ship the historical stdout-only behavior") + assert.Equal(t, DefaultTrafficLogShutdownTimeout, tl.ShutdownTimeout) + + // Path and Endpoint are deliberately empty in both: each is required only + // when its sink is selected, so the template must not quietly supply one. + assert.Equal(t, defaultTrafficLogFileConfig(), tl.File) + assert.Equal(t, defaultTrafficLogHTTPConfig(), tl.HTTP) +} + +func TestDefaultConfigTrafficLoggingPreservesStdout(t *testing.T) { + cfg := defaultConfig() + assert.Equal(t, []string{TrafficLogSinkStdout}, cfg.TrafficLogging.Outputs, + "an existing deployment that upgrades without touching its config must keep stdout") + assert.False(t, cfg.TrafficLogging.Enabled) + assert.Equal(t, DefaultTrafficLogShutdownTimeout, cfg.TrafficLogging.ShutdownTimeout) +} + +// TestResolveTrafficLogFilePath_RejectsTraversal pins that a ".." segment is +// rejected rather than silently resolved. filepath.Clean would turn +// "/var/log/wso2/../../etc/x.log" into "/etc/x.log" — a file written outside the +// volume the operator mounted, and past the chart's mount-containment check. +func TestResolveTrafficLogFilePath_RejectsTraversal(t *testing.T) { + for _, p := range []string{ + "/var/log/wso2/../../etc/traffic.log", + "/var/log/wso2/traffic/../../../traffic.log", + "/../traffic.log", + } { + _, err := ResolveTrafficLogFilePath(p) + assert.Error(t, err, "path %q escapes its directory and must be rejected", p) + } + // A clean absolute path is still accepted, and a single dot is harmless. + for _, p := range []string{"/var/log/wso2/traffic/traffic.log", "/var/log/wso2/./traffic.log"} { + got, err := ResolveTrafficLogFilePath(p) + require.NoError(t, err, "path %q is legitimate", p) + assert.True(t, filepath.IsAbs(got)) + } +} + +// TestEffectiveRetryAbortDepth covers the resolver the HTTP sink uses to decide +// when a retrying batch gives up. The floor matters: a zero depth compares true +// against an empty queue, which would abandon every retry immediately and +// silently turn max_retries into 0. +func TestEffectiveRetryAbortDepth(t *testing.T) { + for _, tc := range []struct { + name string + capacity int + ratio float64 + want int + }{ + // 0 is honoured literally: depth 0, which every queue length satisfies, + // so retries are always abandoned. It is NOT remapped to the default. + {"explicit zero always abandons retries", 10000, 0, 0}, + {"explicit half", 10000, 0.5, 5000}, + {"lower ratio favours draining", 10000, 0.1, 1000}, + {"ratio of 1 never aborts before the queue is full", 10000, 1, 10000}, + // The floor applies only to a non-zero ratio, so rounding cannot silently + // turn a small ratio into "always abandon". + {"small ratio on a tiny queue floors at 1", 1, 0.1, 1}, + {"scales with capacity", 500, 0.5, 250}, + } { + t.Run(tc.name, func(t *testing.T) { + cfg := TrafficLogHTTPConfig{QueueCapacity: tc.capacity, RetryAbortQueueRatio: tc.ratio} + assert.Equal(t, tc.want, cfg.EffectiveRetryAbortDepth()) + }) + } +} + +func TestValidate_RetryAbortQueueRatioBounds(t *testing.T) { + base := func(tl *TrafficLoggingConfig) { + tl.Outputs = []string{TrafficLogSinkHTTP} + tl.HTTP = defaultTrafficLogHTTPConfig() + tl.HTTP.Endpoint = "https://collector.example.com/ingest" + } + for _, r := range []float64{0, 0.25, 1} { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { base(tl); tl.HTTP.RetryAbortQueueRatio = r }) + assert.NoError(t, cfg.Validate(), "ratio %v is valid", r) + } + for _, r := range []float64{-0.1, 1.5} { + cfg := trafficLogConfig(func(tl *TrafficLoggingConfig) { base(tl); tl.HTTP.RetryAbortQueueRatio = r }) + assert.Error(t, cfg.Validate(), "ratio %v must be rejected", r) + } +} + +// TestTrafficLogRetryAbortRatio_AbsentIsNotZero pins the distinction the literal +// semantics depend on: config.Load unmarshals over a pre-populated struct, so an +// omitted key keeps the shipped 0.5 default while an explicit 0 overwrites it. +// If these ever collapsed, "0 means 0" would silently disable retries for every +// deployment that never set the key. +func TestTrafficLogRetryAbortRatio_AbsentIsNotZero(t *testing.T) { + base := ` +[policy_engine] +[policy_engine.config_mode] +mode = "xds" +[traffic_logging] +enabled = true +outputs = ["http"] +[traffic_logging.http] +endpoint = "https://collector.example.com/ingest" +` + load := func(t *testing.T, extra string) *Config { + t.Helper() + p := filepath.Join(t.TempDir(), "c.toml") + require.NoError(t, os.WriteFile(p, []byte(base+extra), 0o600)) + cfg, err := Load(p) + require.NoError(t, err) + return cfg + } + + absent := load(t, "") + assert.Equal(t, DefaultTrafficLogRetryAbortQueueRatio, absent.TrafficLogging.HTTP.RetryAbortQueueRatio, + "an omitted key must keep the shipped default") + assert.Equal(t, 5000, absent.TrafficLogging.HTTP.EffectiveRetryAbortDepth()) + + zero := load(t, "retry_abort_queue_ratio = 0\n") + assert.Equal(t, 0.0, zero.TrafficLogging.HTTP.RetryAbortQueueRatio, + "an explicit 0 must be honoured, not remapped") + assert.Equal(t, 0, zero.TrafficLogging.HTTP.EffectiveRetryAbortDepth(), + "depth 0 means every retry is abandoned") +} diff --git a/gateway/gateway-runtime/policy-engine/internal/metrics/metrics.go b/gateway/gateway-runtime/policy-engine/internal/metrics/metrics.go index 2422e20b4e..8047082807 100644 --- a/gateway/gateway-runtime/policy-engine/internal/metrics/metrics.go +++ b/gateway/gateway-runtime/policy-engine/internal/metrics/metrics.go @@ -62,6 +62,13 @@ var ( StreamErrorsTotal CounterVec RouteLookupFailuresTotal Counter PanicRecoveriesTotal CounterVec + + TrafficLogWrittenTotal CounterVec + TrafficLogDroppedTotal CounterVec + TrafficLogQueueDepth GaugeVec + TrafficLogQueueCapacity GaugeVec + TrafficLogFlushDurationSecond HistogramVec + TrafficLogWriteErrorsTotal CounterVec ) // initMetrics initializes all metric variables. @@ -275,6 +282,71 @@ func initMetrics() { }, []string{"component"}, ) + + // Traffic-log sink metrics. The traffic log carries request/response bodies, + // so silent loss is both an observability gap and a compliance one (an event + // that never reached the log store cannot be audited). dropped_total is the + // series to alert on; the rest exist to diagnose it. + TrafficLogWrittenTotal = newCounterVec( + prometheus.CounterOpts{ + Namespace: namespace, + Name: "traffic_log_written_total", + Help: "Total number of traffic-log lines successfully written, by sink", + }, + []string{"sink"}, + ) + + TrafficLogDroppedTotal = newCounterVec( + prometheus.CounterOpts{ + Namespace: namespace, + Name: "traffic_log_dropped_total", + Help: "Total number of traffic-log lines dropped, by sink and reason " + + "(queue_full, send_failed, write_failed, rotate_failed)", + }, + []string{"sink", "reason"}, + ) + + TrafficLogQueueDepth = newGaugeVec( + prometheus.GaugeOpts{ + Namespace: namespace, + Name: "traffic_log_queue_depth", + Help: "Current number of traffic-log lines queued for delivery, by sink", + }, + []string{"sink"}, + ) + + // Published so an alert can compare depth against capacity as a RATIO. A + // fixed depth threshold is meaningless on its own: 1000 is 10% of the + // default 10000 queue (fires far too early) and unreachable on a queue + // configured smaller than that (never fires at all). + TrafficLogQueueCapacity = newGaugeVec( + prometheus.GaugeOpts{ + Namespace: namespace, + Name: "traffic_log_queue_capacity", + Help: "Configured capacity of the traffic-log delivery queue, by sink", + }, + []string{"sink"}, + ) + + TrafficLogFlushDurationSecond = newHistogramVec( + prometheus.HistogramOpts{ + Namespace: namespace, + Name: "traffic_log_flush_duration_seconds", + Help: "Duration of a traffic-log batch delivery attempt, by sink", + Buckets: []float64{0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0}, + }, + []string{"sink"}, + ) + + TrafficLogWriteErrorsTotal = newCounterVec( + prometheus.CounterOpts{ + Namespace: namespace, + Name: "traffic_log_write_errors_total", + Help: "Total number of traffic-log delivery errors, by sink and code " + + "(HTTP status, or a short error class for local sinks)", + }, + []string{"sink", "code"}, + ) } func registerCounterVec(v CounterVec) { @@ -375,6 +447,13 @@ func initRegistry() { registerCounter(RouteLookupFailuresTotal) registerCounterVec(PanicRecoveriesTotal) + registerCounterVec(TrafficLogWrittenTotal) + registerCounterVec(TrafficLogDroppedTotal) + registerGaugeVec(TrafficLogQueueDepth) + registerGaugeVec(TrafficLogQueueCapacity) + registerHistogramVec(TrafficLogFlushDurationSecond) + registerCounterVec(TrafficLogWriteErrorsTotal) + Up.Set(1) } diff --git a/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server.go b/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server.go index e9715f7f9c..a5919fc825 100644 --- a/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server.go +++ b/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server.go @@ -82,7 +82,12 @@ func (s *AccessLogServiceServer) StreamAccessLogs(stream v3.AccessLogService_Str } // StartAccessLogServiceServer starts the Access Log Service Server. -func StartAccessLogServiceServer(cfg *config.Config) *grpc.Server { +// +// It returns the gRPC server and the Analytics instance behind it. The caller owns +// shutdown ordering: stop the gRPC server first so no new events arrive, then call +// Analytics.Close to flush publishers that buffer (the traffic-log HTTP sink, +// Moesif). Without that flush, an in-flight batch is lost on every pod restart. +func StartAccessLogServiceServer(cfg *config.Config) (*grpc.Server, *analytics.Analytics) { // Create a new instance of the Access Log Service Server accessLogServiceServer := newAccessLogServiceServer(cfg) @@ -160,5 +165,5 @@ func StartAccessLogServiceServer(cfg *config.Config) *grpc.Server { }() } - return server + return server, accessLogServiceServer.analytics } diff --git a/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server_test.go b/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server_test.go index c0ed6a3db1..f1f1511b8e 100644 --- a/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server_test.go +++ b/gateway/gateway-runtime/policy-engine/internal/utils/access_logger_server_test.go @@ -222,7 +222,7 @@ func TestStartAccessLogServiceServer_TCP(t *testing.T) { } // Start the server - grpcServer := StartAccessLogServiceServer(cfg) + grpcServer, _ := StartAccessLogServiceServer(cfg) require.NotNil(t, grpcServer) diff --git a/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-config.yaml b/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-config.yaml index 36218eea4d..28abdfd3e0 100644 --- a/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-config.yaml +++ b/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-config.yaml @@ -428,7 +428,7 @@ data: {{- if .Values.gateway.config.traffic_logging.masked_headers }} masked_headers = [{{- range $i, $h := .Values.gateway.config.traffic_logging.masked_headers }}{{- if gt $i 0 }}, {{ end }}{{ $h | quote }}{{- end }}] {{- end }} - {{- if .Values.gateway.config.traffic_logging.max_payload_size }} + {{- if not (kindIs "invalid" .Values.gateway.config.traffic_logging.max_payload_size) }} max_payload_size = {{ .Values.gateway.config.traffic_logging.max_payload_size | int64 }} {{- end }} {{- if .Values.gateway.config.traffic_logging.request_headers }} @@ -446,6 +446,12 @@ data: {{- if .Values.gateway.config.traffic_logging.exclude_fields }} exclude_fields = [{{- range $i, $f := .Values.gateway.config.traffic_logging.exclude_fields }}{{- if gt $i 0 }}, {{ end }}{{ $f | quote }}{{- end }}] {{- end }} + {{- if .Values.gateway.config.traffic_logging.outputs }} + outputs = [{{- range $i, $o := .Values.gateway.config.traffic_logging.outputs }}{{- if gt $i 0 }}, {{ end }}{{ $o | quote }}{{- end }}] + {{- end }} + {{- if not (kindIs "invalid" .Values.gateway.config.traffic_logging.shutdown_timeout) }} + shutdown_timeout = {{ .Values.gateway.config.traffic_logging.shutdown_timeout | quote }} + {{- end }} {{- if .Values.gateway.config.traffic_logging.properties }} [traffic_logging.properties] @@ -453,6 +459,142 @@ data: {{ $key }} = {{ $value | quote }} {{- end }} {{- end }} + {{- with .Values.gateway.config.traffic_logging.file }} + + [traffic_logging.file] + {{- if .path }} + path = {{ .path | quote }} + {{- end }} + {{- if not (kindIs "invalid" .max_size_mb) }} + max_size_mb = {{ .max_size_mb | int64 }} + {{- end }} + {{- end }} + {{- with .Values.gateway.config.traffic_logging.http }} + + [traffic_logging.http] + {{- if .endpoint }} + endpoint = {{ .endpoint | quote }} + {{- end }} + {{- if .content_type }} + content_type = {{ .content_type | quote }} + {{- end }} + {{- if kindIs "bool" .allow_insecure_transport }} + allow_insecure_transport = {{ .allow_insecure_transport }} + {{- end }} + {{- if not (kindIs "invalid" .batch_max_events) }} + batch_max_events = {{ .batch_max_events | int64 }} + {{- end }} + {{- if not (kindIs "invalid" .batch_max_bytes) }} + batch_max_bytes = {{ .batch_max_bytes | int64 }} + {{- end }} + {{- if not (kindIs "invalid" .flush_interval) }} + flush_interval = {{ .flush_interval | quote }} + {{- end }} + {{- if not (kindIs "invalid" .queue_capacity) }} + queue_capacity = {{ .queue_capacity | int64 }} + {{- end }} + {{- if .on_queue_full }} + on_queue_full = {{ .on_queue_full | quote }} + {{- end }} + {{- if not (kindIs "invalid" .request_timeout) }} + request_timeout = {{ .request_timeout | quote }} + {{- end }} + {{- if not (kindIs "invalid" .max_retries) }} + max_retries = {{ .max_retries | int64 }} + {{- end }} + {{- if not (kindIs "invalid" .retry_backoff) }} + retry_backoff = {{ .retry_backoff | quote }} + {{- end }} + {{- if not (kindIs "invalid" .retry_abort_queue_ratio) }} + retry_abort_queue_ratio = {{ .retry_abort_queue_ratio }} + {{- end }} + {{- with .auth }} + {{- /* + config.toml is rendered into a ConfigMap, which is not a Secret: it is + readable by anything with configmap read access in the namespace, stored + unencrypted in etcd by default, and echoed by `helm get values`. Every + other credential in this file (postgres/database password, controlplane + token) is therefore rendered as an `{{ env ... }}` interpolation token and + injected from a Secret at runtime, never as a literal. + + Hold the traffic-log credentials to the same standard: require an + `{{ env }}` or `{{ file }}` token, which the policy engine resolves at load + time and never logs. Fail rather than quietly writing the secret into the + ConfigMap. allow_plaintext_credentials exists as a deliberate, off-by-default + escape hatch for local development. + */ -}} + {{- /* + Compare as a string: any non-empty string is truthy in a Go template, so a + quoted `allow_plaintext_credentials: "false"` would otherwise DISABLE this + guard and leak the credential — the opposite of what it says. Only a real + true (bare or quoted) opts out; anything else stays default-deny. + */ -}} + {{- $allowPlain := false -}} + {{- if hasKey . "allow_plaintext_credentials" -}} + {{- $allowPlain = eq (toString .allow_plaintext_credentials) "true" -}} + {{- end -}} + {{- if not $allowPlain -}} + {{- $whole := "^\\{\\{-? *(env|file) [^{}]*\\}\\}$" -}} + {{- $suffixed := "^[^{}]*\\{\\{-? *(env|file) [^{}]*\\}\\}$" -}} + {{- $sensitive := dict -}} + {{- with .bearer }}{{- if .token }}{{- $sensitive = set $sensitive "auth.bearer.token" (dict "v" .token "re" $whole) }}{{- end }}{{- end -}} + {{- with .basic }}{{- if .password }}{{- $sensitive = set $sensitive "auth.basic.password" (dict "v" .password "re" $whole) }}{{- end }}{{- end -}} + {{- with .header }}{{- if .value }}{{- $sensitive = set $sensitive "auth.header.value" (dict "v" .value "re" $suffixed) }}{{- end }}{{- end -}} + {{- range $field, $spec := $sensitive -}} + {{- $val := toString $spec.v -}} + {{- if not (regexMatch $spec.re (trim $val)) -}} + {{- fail (printf "gateway.config.traffic_logging.http.%s holds a literal value, which would be written in plaintext into the gateway ConfigMap. Supply it as an interpolation token resolved at runtime instead, e.g. '{{ env \"APIP_GW_TRAFFIC_LOG_TOKEN\" }}' or '{{ file \"/secrets/gateway-runtime/hec-token\" }}' (allowed source dirs: /etc/gateway-runtime, /secrets/gateway-runtime). Set gateway.config.traffic_logging.http.auth.allow_plaintext_credentials=true only for local development." $field) -}} + {{- end -}} + {{- end -}} + {{- end }} + + [traffic_logging.http.auth] + type = {{ .type | default "none" | quote }} + {{- with .bearer }} + + [traffic_logging.http.auth.bearer] + {{- if .token }} + token = {{ .token | quote }} + {{- end }} + {{- end }} + {{- with .basic }} + + [traffic_logging.http.auth.basic] + {{- if .username }} + username = {{ .username | quote }} + {{- end }} + {{- if .password }} + password = {{ .password | quote }} + {{- end }} + {{- end }} + {{- with .header }} + + [traffic_logging.http.auth.header] + {{- if .name }} + name = {{ .name | quote }} + {{- end }} + {{- if .value }} + value = {{ .value | quote }} + {{- end }} + {{- end }} + {{- end }} + {{- with .tls }} + + [traffic_logging.http.tls] + {{- if .ca_file }} + ca_file = {{ .ca_file | quote }} + {{- end }} + {{- if .cert_file }} + cert_file = {{ .cert_file | quote }} + {{- end }} + {{- if .key_file }} + key_file = {{ .key_file | quote }} + {{- end }} + {{- if kindIs "bool" .insecure_skip_verify }} + insecure_skip_verify = {{ .insecure_skip_verify }} + {{- end }} + {{- end }} + {{- end }} {{- end }} {{- if .Values.gateway.config.tracing }} diff --git a/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-runtime/deployment.yaml b/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-runtime/deployment.yaml index 3b9ffc9f02..8492a304a0 100644 --- a/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-runtime/deployment.yaml +++ b/kubernetes/helm/gateway-helm-chart/templates/gateway/gateway-runtime/deployment.yaml @@ -2,6 +2,34 @@ {{- $deployment := $unified.deployment -}} {{- $policies := $unified.policies -}} {{- $config := .Values.gateway.config -}} +{{- $trafficLogVolume := $unified.trafficLogVolume | default dict -}} +{{- $fileSinkSelected := false -}} +{{- if and $config.traffic_logging $config.traffic_logging.outputs -}} + {{- range $config.traffic_logging.outputs -}} + {{- if eq (lower (trim .)) "file" -}}{{- $fileSinkSelected = true -}}{{- end -}} + {{- end -}} +{{- end -}} +{{- $trafficLogVolume = merge (dict) $trafficLogVolume (dict "mountPath" "/var/log/wso2" "sizeLimit" "512Mi") -}} +{{- $tlvEnabled := $fileSinkSelected -}} +{{- if hasKey $trafficLogVolume "enabled" -}} + {{- $tlvEnabled = $trafficLogVolume.enabled -}} +{{- end -}} +{{- $trafficLogVolume = set $trafficLogVolume "enabled" $tlvEnabled -}} +{{- if and $trafficLogVolume.enabled $fileSinkSelected -}} + {{- $logPath := "" -}} + {{- if $config.traffic_logging.file -}}{{- $logPath = $config.traffic_logging.file.path | default "" -}}{{- end -}} + {{- /* + Normalize before comparing. hasPrefix on the raw string would accept + "/var/log/wso2/../../etc/x.log", which shares the mount prefix textually but + resolves outside it. `clean` collapses the traversal so the check sees the + path the process will actually open. + */ -}} + {{- $logPath = clean $logPath -}} + {{- $mount := printf "%s/" (trimSuffix "/" (clean $trafficLogVolume.mountPath)) -}} + {{- if and $logPath (not (hasPrefix $mount $logPath)) -}} + {{- fail (printf "gateway.config.traffic_logging.file.path (%q) is not under gateway.gatewayRuntime.trafficLogVolume.mountPath (%q), so it would not land on the mounted volume and the gateway-runtime pod would fail to start. Move the path under the mount, change the mountPath, or set trafficLogVolume.enabled=false if you are mounting your own volume." $logPath $trafficLogVolume.mountPath) -}} + {{- end -}} +{{- end -}} {{- if $deployment.enabled }} apiVersion: apps/v1 kind: Deployment @@ -173,6 +201,10 @@ spec: subPath: model_prices.json readOnly: true {{- end }} + {{- if $trafficLogVolume.enabled }} + - name: traffic-log + mountPath: {{ $trafficLogVolume.mountPath | quote }} + {{- end }} {{- with $deployment.extraVolumeMounts }} {{- toYaml . | nindent 12 }} {{- end }} @@ -185,6 +217,23 @@ spec: configMap: name: {{ default (printf "%s-llm-pricing" (include "gateway-operator.fullname" .)) $policies.llmPricing.configMapName }} {{- end }} + {{- if $trafficLogVolume.enabled }} + {{- /* + Writable volume for the traffic_logging "file" sink. + request and response bodies written here are invisible + to `kubectl logs` and to any DaemonSet or host forwarder shipping + container logs onward. + sizeLimit must stay comfortably ABOVE 2 x traffic_logging.file.max_size_mb + */}} + - name: traffic-log + emptyDir: + {{- if $trafficLogVolume.sizeLimit }} + sizeLimit: {{ $trafficLogVolume.sizeLimit }} + {{- end }} + {{- if $trafficLogVolume.medium }} + medium: {{ $trafficLogVolume.medium | quote }} + {{- end }} + {{- end }} {{- with $deployment.extraVolumes }} {{- toYaml . | nindent 8 }} {{- end }} diff --git a/kubernetes/helm/gateway-helm-chart/values.yaml b/kubernetes/helm/gateway-helm-chart/values.yaml index e49adfc5b1..4e9b743fe6 100644 --- a/kubernetes/helm/gateway-helm-chart/values.yaml +++ b/kubernetes/helm/gateway-helm-chart/values.yaml @@ -839,6 +839,33 @@ gateway: tag: "1.2.0" pullPolicy: Always imagePullSecrets: [] + + # Writable volume backing the traffic_logging "file" sink. + # + # A shared RWX volume, hostPath, or NFS mount written by more + # than one gateway replica is not supported and will silently break traffic logging. + # When one pod rotates the file the others keep writing to the descriptor they + # already hold, so their lines land in the backup and are clobbered by the next + # rotation; each pod also tracks the file size in memory, so with several + # writers the ceiling triggers late or never. The default emptyDir below is + # per-pod and therefore correct. Scale out by giving each replica its own + # volume, not by sharing one. + # + # An emptyDir lives outside the /var/log/pods glob node-level collectors + # read, which is the point — bodies written here are invisible to both + # `kubectl logs` and any DaemonSet shipping container logs onward. + # + # Keep sizeLimit above 2 x traffic_logging.file.max_size_mb so rotation + # bounds the file, not the kubelet — the kubelet's limit EVICTS the pod. + trafficLogVolume: + # enabled is auto-derived from whether traffic_logging.outputs contains "file". + # Uncomment only to override; leaving it commented is what keeps the auto-provisioning working. + # enabled: true + mountPath: /var/log/wso2 + sizeLimit: 512Mi + # medium: "Memory" # tmpfs — off disk entirely, but counts against + # the container's memory limit. + service: type: LoadBalancer annotations: {}