From d84f0437191187101a66280d9b5e48e2138f83be Mon Sep 17 00:00:00 2001 From: Andy Bonventre Date: Wed, 15 Jul 2026 19:33:12 -0400 Subject: [PATCH] feat(postgres): capture application_name in the request log for connection tracing --- CHANGELOG.md | 8 + docs/content/concepts/06-observability.md | 1 + .../concepts/08-postgres-data-plane.md | 8 + docs/content/guides/13-postgres-neon.md | 12 ++ gatekeeper.go | 17 +- gatekeeper_test.go | 156 ++++++++++++++++++ proxy/pgtest_test.go | 22 ++- proxy/postgres.go | 7 + proxy/postgres_test.go | 155 ++++++++++++++++- proxy/proxy.go | 46 ++++++ proxy/proxy_test.go | 50 ++++++ 11 files changed, 465 insertions(+), 17 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 023ae9f..ffd4d27 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,14 @@ Gatekeeper is a standalone credential-injecting TLS-intercepting proxy. It trans Gatekeeper is pre-1.0. The configuration schema and credential source interface may change between minor versions. +## v0.20.0 — 2026-07-15 + +### Added + +- **The Postgres data-plane request log now captures the client's `application_name` startup parameter as a tracing slug** — the Postgres analogue of the HTTP `capture_headers` feature. A run can open many Postgres connections over its lifetime, and until now the canonical log line's only per-connection handle was `run_id`, which identifies the *run* but not which caller within it opened a given connection. Standard Postgres clients already let a caller label a connection via `PGAPPNAME`, a driver's `application_name=` connection option, or `libpq`'s `application_name` keyword; gatekeeper now reads that value out of the client's `StartupMessage` parameters (`proxy.RunContextData` continues to forward it upstream unchanged, so it still surfaces in Neon's own `pg_stat_activity` too) and records it on `RequestLogData.ApplicationName` (`proxy/proxy.go`), which `serveAuthenticated` (`proxy/postgres.go`) populates on every audit-log exit path — including denied connections (no resolver, network-policy denial), so a rejected connection is still traceable back to its origin, not just a successful one. `gatekeeper.go`'s canonical-log-line callback emits it as an `application_name` slog attribute, gated on non-empty exactly like `run_id`/`client_ip`. + Because `application_name` is client-supplied, unauthenticated free text with no protocol grammar constraining it (unlike an HTTP header value), it is sanitized before it ever reaches a log line: a new shared helper, `proxy.SanitizeLogValue`, discards invalid UTF-8, strips control characters (newlines, carriage returns, NUL, tabs, ...) so a crafted value can't forge additional log lines or otherwise corrupt structured log output, and bounds the result to 256 bytes, truncating at a valid UTF-8 boundary rather than splitting a multi-byte rune. `gatekeeper.go`'s existing `capture_headers` truncation logic — previously inlined and only bounding length, never stripping control characters — now calls the same helper, so both capture paths share one bound and one sanitization behavior. + `application_name` is a correlation slug the client controls, not a trusted identity — `run_id`, populated only from the authenticated run token, remains the trusted identity for anything security-relevant. Documented in the [observability](docs/content/concepts/06-observability.md) canonical-log-field table and a new "Tracing a connection to its origin" section in the [Postgres data plane](docs/content/concepts/08-postgres-data-plane.md) and [Postgres + Neon](docs/content/guides/13-postgres-neon.md) docs + ## v0.19.1 — 2026-07-15 ### Fixed diff --git a/docs/content/concepts/06-observability.md b/docs/content/concepts/06-observability.md index e57c81b..8a293c2 100644 --- a/docs/content/concepts/06-observability.md +++ b/docs/content/concepts/06-observability.md @@ -64,6 +64,7 @@ Gatekeeper emits one wide structured log entry per request at completion. Each l | `error` | Error message, when the request ended in an error | | `run_id` | Per-run identifier (daemon mode) | | `user_id` | User ID from proxy auth username | +| `application_name` | Postgres connections only: the client's `application_name` startup parameter, sanitized and length-bounded. A correlation slug the client sets, not a trusted identity — see [Postgres Data Plane](./08-postgres-data-plane.md#tracing-a-connection-to-its-origin). Omitted when the client didn't set one. | Log level is determined by outcome: `ERROR` for server errors or transport failures, `WARN` for policy denials or client errors, `INFO` for successful requests. diff --git a/docs/content/concepts/08-postgres-data-plane.md b/docs/content/concepts/08-postgres-data-plane.md index f3d55a7..6a94831 100644 --- a/docs/content/concepts/08-postgres-data-plane.md +++ b/docs/content/concepts/08-postgres-data-plane.md @@ -48,6 +48,14 @@ A credential with a `postgres` block selects how the upstream password is resolv The API key is itself a credential source, so it can come from an environment variable, AWS Secrets Manager, or GCP Secret Manager. See [Credential Sources](./03-credential-sources.md). +## Tracing a connection to its origin + +The audit entry's `run_id` is the trusted identity: it comes from the authenticated run token, so a client cannot forge it. But `run_id` alone doesn't say *which* connection within a run produced a given log line — a single run can open many Postgres connections over its lifetime. + +Clients can additionally set the standard Postgres `application_name` startup parameter (via `PGAPPNAME`, a driver's `application_name=` connection option, or `libpq`'s `application_name` keyword) to a short slug identifying the connection's origin, e.g. a box or worker ID. Gatekeeper captures it into the canonical log line as `application_name` (see [Canonical log lines](./06-observability.md#canonical-log-lines)) — sanitized (control characters stripped) and length-bounded before logging, the Postgres analogue of the HTTP [`capture_headers`](./06-observability.md#canonical-log-lines) feature. The raw value is still forwarded upstream unchanged, so it also surfaces in Neon's own `pg_stat_activity`, giving the same slug on both sides of the proxy. + +Unlike `run_id`, `application_name` is not authenticated: the client sets it, so treat it as a correlation hint for debugging, not as proof of origin. + ## Security properties - Run-token comparison uses the same constant-time path as the HTTP plane. diff --git a/docs/content/guides/13-postgres-neon.md b/docs/content/guides/13-postgres-neon.md index 0d75bc9..dbf0eb2 100644 --- a/docs/content/guides/13-postgres-neon.md +++ b/docs/content/guides/13-postgres-neon.md @@ -114,6 +114,18 @@ PGPASSWORD=local-test-token psql \ `host` never touches DNS here — it only sets SNI — so this works even for endpoint hostnames that don't resolve from your machine at all. +## Tracing a connection to its origin + +Set `application_name` to identify which caller opened a given connection in gatekeeper's logs: + +```bash +PGAPPNAME=box-abc123 PGPASSWORD=local-test-token psql \ + "host=ep-cool-darkness-123456.us-east-2.aws.neon.tech \ + dbname=neondb user=neondb_owner sslmode=require" +``` + +Gatekeeper captures it (sanitized) as `application_name` on the canonical log line, alongside the authenticated `run_id`. It's forwarded upstream unchanged too, so it also shows up in Neon's `pg_stat_activity` — but unlike `run_id`, it's client-set and not authenticated. See [Tracing a connection to its origin](../concepts/08-postgres-data-plane.md#tracing-a-connection-to-its-origin). + ## Static resolver alternative For a non-Neon Postgres server, or to pin a single fixed password instead of calling the Neon API, use `resolver: static`. The source supplies the password directly and gatekeeper fetches it once at startup: diff --git a/gatekeeper.go b/gatekeeper.go index 415ccb2..24ea6e8 100644 --- a/gatekeeper.go +++ b/gatekeeper.go @@ -24,7 +24,6 @@ import ( "strings" "sync" "time" - "unicode/utf8" "github.com/majorcontext/gatekeeper/credentialsource" "github.com/majorcontext/gatekeeper/proxy" @@ -313,6 +312,11 @@ func New(ctx context.Context, cfg *Config, version string) (*Server, error) { } attrs = append(attrs, slog.String("client_ip", clientIP)) } + if data.ApplicationName != "" { + // A correlation slug the client set (e.g. via PGAPPNAME), not a + // trusted identity — run_id, above, is the trusted identity. + attrs = append(attrs, slog.String("application_name", data.ApplicationName)) + } if data.AuthInjected { attrs = append(attrs, slog.Bool("credential_injected", true)) var headerNames []string @@ -348,18 +352,13 @@ func New(ctx context.Context, cfg *Config, version string) (*Server, error) { } // Append captured request headers as structured log attributes. + // SanitizeLogValue bounds and cleans the value the same way + // data.ApplicationName above already was — see its doc comment. if data.RequestHeaders != nil { for _, h := range cfg.Log.CaptureHeaders { if v := data.RequestHeaders.Get(h); v != "" { - if len(v) > 256 { - // Truncate at a valid UTF-8 boundary to avoid splitting multi-byte characters. - v = v[:256] - for len(v) > 0 && !utf8.ValidString(v) { - v = v[:len(v)-1] - } - } key := strings.ReplaceAll(strings.ToLower(h), "-", "_") - attrs = append(attrs, slog.String(key, v)) + attrs = append(attrs, slog.String(key, proxy.SanitizeLogValue(v))) } } } diff --git a/gatekeeper_test.go b/gatekeeper_test.go index d086981..b997054 100644 --- a/gatekeeper_test.go +++ b/gatekeeper_test.go @@ -2929,6 +2929,162 @@ func TestServerPostgresProxyProtocol(t *testing.T) { } } +// TestServerPostgresLogsApplicationName verifies gatekeeper's canonical +// "request" log line -- the slog attrs wired in New()'s p.SetLogger callback, +// not just the RequestLogData the proxy package hands it -- carries an +// application_name attribute for a client-set Postgres application_name +// startup parameter (the Postgres analogue of the HTTP capture_headers +// feature), and that the attribute is entirely absent, not merely empty, +// when the client never set one -- the same non-empty gating run_id and +// client_ip already get. +func TestServerPostgresLogsApplicationName(t *testing.T) { + tests := []struct { + name string + applicationName string + wantSubstring string + wantAbsent string + }{ + { + name: "present", + applicationName: "box-abc123", + wantSubstring: "application_name=box-abc123", + }, + { + name: "absent when the client does not set it", + wantAbsent: "application_name=", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + caDir := t.TempDir() + ca, err := proxy.NewCA(caDir) + if err != nil { + t.Fatalf("NewCA: %v", err) + } + caPool := x509.NewCertPool() + if !caPool.AppendCertsFromPEM(ca.CertPEM()) { + t.Fatal("failed to add CA cert to pool") + } + + cfg := &Config{ + Proxy: ProxyConfig{Port: 0, Host: "127.0.0.1"}, + TLS: TLSConfig{ + CACert: filepath.Join(caDir, "ca.crt"), + CAKey: filepath.Join(caDir, "ca.key"), + }, + Postgres: &PostgresConfig{Port: 0}, + Credentials: []CredentialConfig{ + { + Host: "*.neon.tech", + Postgres: &PostgresCredentialConfig{Resolver: "static"}, + Source: SourceConfig{Type: "static", Value: "pw"}, + }, + }, + } + + srv, err := New(context.Background(), cfg, "") + if err != nil { + t.Fatalf("New: %v", err) + } + // Deliberately do NOT override SetLogger here (unlike + // captureServerLog elsewhere in this file): this test exercises the + // real slog-emitting logger New() installs. + logBuf := captureDefaultSlog(t) + + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + go func() { _ = srv.Start(ctx) }() + + deadline := time.Now().Add(2 * time.Second) + var pgAddr string + for { + pgAddr = srv.PostgresAddr() + if pgAddr != "" { + break + } + if time.Now().After(deadline) { + t.Fatal("postgres listener did not start in time") + } + time.Sleep(10 * time.Millisecond) + } + + conn, err := net.DialTimeout("tcp", pgAddr, time.Second) + if err != nil { + t.Fatalf("dial postgres listener: %v", err) + } + defer conn.Close() + conn.SetDeadline(time.Now().Add(2 * time.Second)) + + frontend := pgproto3.NewFrontend(conn, conn) + frontend.Send(&pgproto3.SSLRequest{}) + if err := frontend.Flush(); err != nil { + t.Fatalf("send SSLRequest: %v", err) + } + buf := make([]byte, 1) + if _, err := io.ReadFull(conn, buf); err != nil { + t.Fatalf("read SSLRequest response: %v", err) + } + if buf[0] != 'S' { + t.Fatalf("SSLRequest response = %q, want 'S'", buf[0]) + } + + // db.test.local matches no configured credential host, so the + // connection is denied for lack of a resolver -- but only after the + // deny path logs the canonical "request" line, which is all this + // test needs (see TestServerPostgresProxyProtocol for the same + // pattern). + tlsConn := tls.Client(conn, &tls.Config{ServerName: "db.test.local", RootCAs: caPool}) + if err := tlsConn.Handshake(); err != nil { + t.Fatalf("TLS handshake: %v", err) + } + defer tlsConn.Close() + + params := map[string]string{"user": "app", "database": "appdb"} + if tt.applicationName != "" { + params["application_name"] = tt.applicationName + } + fe := pgproto3.NewFrontend(tlsConn, tlsConn) + fe.Send(&pgproto3.StartupMessage{ + ProtocolVersion: pgproto3.ProtocolVersionNumber, + Parameters: params, + }) + if err := fe.Flush(); err != nil { + t.Fatalf("send startup: %v", err) + } + if _, err := fe.Receive(); err != nil { + t.Fatalf("receive auth request: %v", err) + } + fe.Send(&pgproto3.PasswordMessage{Password: "any-token"}) + if err := fe.Flush(); err != nil { + t.Fatalf("send password: %v", err) + } + if _, err := fe.Receive(); err != nil { + t.Fatalf("receive auth result: %v", err) + } + + // The log line is written by a goroutine handling the connection, + // racing this one; poll briefly for it to land. + var text string + logDeadline := time.Now().Add(2 * time.Second) + for time.Now().Before(logDeadline) { + text = logBuf.String() + if strings.Contains(text, "proxy_type=postgres") { + break + } + time.Sleep(10 * time.Millisecond) + } + + if tt.wantSubstring != "" && !strings.Contains(text, tt.wantSubstring) { + t.Errorf("log output does not contain %q; got:\n%s", tt.wantSubstring, text) + } + if tt.wantAbsent != "" && strings.Contains(text, tt.wantAbsent) { + t.Errorf("log output unexpectedly contains %q; got:\n%s", tt.wantAbsent, text) + } + }) + } +} + func TestServerPostgresStartFailureCleansUpHTTP(t *testing.T) { // Occupy a port so the postgres listener fails to bind to it. occupied, err := net.Listen("tcp", "127.0.0.1:0") diff --git a/proxy/pgtest_test.go b/proxy/pgtest_test.go index 48302fd..699504c 100644 --- a/proxy/pgtest_test.go +++ b/proxy/pgtest_test.go @@ -96,10 +96,11 @@ type fakePostgresServer struct { // assert the message is surfaced in gatekeeper's logs set it explicitly. failPostAuthMessage string - mu sync.Mutex - authOK int - authFail int - lastQuery string + mu sync.Mutex + authOK int + authFail int + lastQuery string + lastStartupParams map[string]string } // fakePostgresOption customizes a fakePostgresServer before it starts serving. @@ -140,6 +141,16 @@ func (f *fakePostgresServer) queriedLast() string { return f.lastQuery } +// lastApplicationName returns the "application_name" startup parameter the +// proxy forwarded upstream on the most recent connection, letting a test +// verify that capturing application_name for the request log does not +// mutate what actually gets forwarded to the real database. +func (f *fakePostgresServer) lastApplicationName() string { + f.mu.Lock() + defer f.mu.Unlock() + return f.lastStartupParams["application_name"] +} + // startFakePostgres starts a fake Postgres server on 127.0.0.1:0. The listener // is closed via t.Cleanup. func startFakePostgres(t *testing.T, dnsName, user, password string, opts ...fakePostgresOption) *fakePostgresServer { @@ -231,6 +242,9 @@ func (f *fakePostgresServer) handle(conn net.Conn) { if !ok { return } + f.mu.Lock() + f.lastStartupParams = sm.Parameters + f.mu.Unlock() if sm.Parameters["user"] != f.user { // 28000 invalid_authorization_specification: what real Postgres sends // for an unknown role. diff --git a/proxy/postgres.go b/proxy/postgres.go index 11c40fc..ccc63fe 100644 --- a/proxy/postgres.go +++ b/proxy/postgres.go @@ -802,6 +802,13 @@ func (s *PostgresServer) serveAuthenticated(ctx context.Context, clientConn net. RequestSize: -1, ResponseSize: -1, ClientAddr: clientConn.RemoteAddr().String(), + // ApplicationName is a tracing slug, not identity: it comes straight + // from the client's startup parameters, unauthenticated, so it is + // sanitized before it ever reaches a log line. The raw value in + // startupParams is left untouched — it is still forwarded upstream + // as-is (see connectWithRetry) so Neon's own pg_stat_activity keeps + // seeing exactly what the client sent. + ApplicationName: SanitizeLogValue(startupParams["application_name"]), } if rc != nil { logEntry.RunID = rc.RunID diff --git a/proxy/postgres_test.go b/proxy/postgres_test.go index 9364e51..51d4ad5 100644 --- a/proxy/postgres_test.go +++ b/proxy/postgres_test.go @@ -253,21 +253,23 @@ func newTestPostgresListenerWithProxyProtocol(t *testing.T, p *Proxy) *PostgresS // message, and answers AuthenticationCleartextPassword with password. It returns // the message received after sending the password (the auth result or an error) // and the TLS conn so the caller can Close it. caPool trusts the proxy CA. -func pgClientHandshake(t *testing.T, addr, sniHost string, caPool *x509.CertPool, user, db, password string) (pgproto3.BackendMessage, net.Conn) { +// extraParams, when non-nil, is merged into the StartupMessage's Parameters +// alongside user/database (e.g. {"application_name": "box-abc123"}). +func pgClientHandshake(t *testing.T, addr, sniHost string, caPool *x509.CertPool, user, db, password string, extraParams ...map[string]string) (pgproto3.BackendMessage, net.Conn) { t.Helper() raw, err := net.Dial("tcp", addr) if err != nil { t.Fatalf("dial: %v", err) } - return pgClientHandshakeOnConn(t, raw, sniHost, caPool, user, db, password) + return pgClientHandshakeOnConn(t, raw, sniHost, caPool, user, db, password, extraParams...) } // pgClientHandshakeOnConn is pgClientHandshake but driven over an // already-established raw connection, letting a caller write bytes ahead of // the Postgres wire protocol — e.g. a PROXY protocol header — before the // handshake begins. -func pgClientHandshakeOnConn(t *testing.T, raw net.Conn, sniHost string, caPool *x509.CertPool, user, db, password string) (pgproto3.BackendMessage, net.Conn) { +func pgClientHandshakeOnConn(t *testing.T, raw net.Conn, sniHost string, caPool *x509.CertPool, user, db, password string, extraParams ...map[string]string) (pgproto3.BackendMessage, net.Conn) { t.Helper() _ = raw.SetDeadline(time.Now().Add(10 * time.Second)) @@ -300,6 +302,11 @@ func pgClientHandshakeOnConn(t *testing.T, raw net.Conn, sniHost string, caPool if db != "" { params["database"] = db } + for _, extra := range extraParams { + for k, v := range extra { + params[k] = v + } + } fe = pgproto3.NewFrontend(tlsConn, tlsConn) fe.Send(&pgproto3.StartupMessage{ ProtocolVersion: pgproto3.ProtocolVersionNumber, @@ -648,13 +655,22 @@ func TestPostgresStopNilListenerIsSafe(t *testing.T) { // connectThroughGatekeeper drives a real pgx client through the gatekeeper // Postgres listener: it authenticates with token (the run token, sent as the // cleartext password) and presents sniHost as the TLS server name. -func connectThroughGatekeeper(t *testing.T, srv *PostgresServer, caPool *x509.CertPool, sniHost, user, db, token string) (*pgconn.PgConn, error) { +// connectThroughGatekeeper connects through the gatekeeper Postgres listener. +// Any runtimeParams maps are merged into the connection's startup parameters +// (e.g. {"application_name": "box-abc123"}), letting a caller exercise +// startup parameters beyond user/database. +func connectThroughGatekeeper(t *testing.T, srv *PostgresServer, caPool *x509.CertPool, sniHost, user, db, token string, runtimeParams ...map[string]string) (*pgconn.PgConn, error) { t.Helper() cfg, err := pgconn.ParseConfig(fmt.Sprintf("postgres://%s:%s@%s/%s", user, token, srv.Addr(), db)) if err != nil { t.Fatal(err) } cfg.TLSConfig = &tls.Config{ServerName: sniHost, RootCAs: caPool} + for _, params := range runtimeParams { + for k, v := range params { + cfg.RuntimeParams[k] = v + } + } ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() return pgconn.ConnectConfig(ctx, cfg) @@ -770,6 +786,137 @@ func TestPostgresEndToEnd(t *testing.T) { } } +// TestPostgresLogsApplicationName verifies that the client-supplied Postgres +// "application_name" startup parameter is captured into the request log as a +// tracing slug -- the Postgres analogue of the HTTP capture_headers feature. +// application_name is a correlation slug the client sets (e.g. a box ID), +// not a trusted identity: RunID, populated from the authenticated run token, +// remains the trusted identity. Each case also confirms that capturing for +// the log does not disturb what gatekeeper forwards to the real upstream +// server -- the fake upstream must always see the client's raw, +// un-sanitized value. +func TestPostgresLogsApplicationName(t *testing.T) { + tests := []struct { + name string + applicationName string // what the client sends; "" means the parameter is omitted entirely + wantLogged string // what should land in the log entry + }{ + { + name: "captured verbatim when clean", + applicationName: "box-abc123", + wantLogged: "box-abc123", + }, + { + name: "absent when the client does not set it", + wantLogged: "", + }, + { + name: "sanitized: control characters stripped and value bounded", + applicationName: "box-abc\r\n123" + strings.Repeat("x", 300), + wantLogged: "box-abc123" + strings.Repeat("x", maxCapturedLogValueLen-len("box-abc123")), + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + fake := startFakePostgres(t, "ep-foo-123.aws.neon.tech", "app_rw", "real-password") + + ca, err := generateCA() + if err != nil { + t.Fatalf("generateCA: %v", err) + } + p := NewProxy() + p.SetCA(ca) + p.SetUpstreamCAs(fake.certPool) + p.SetAuthToken("run-token") + p.SetPostgresResolver("*.neon.tech", NewStaticPostgresResolver("real-password")) + cap := &logCapture{} + p.SetLogger(cap.log) + + srv := newTestPostgresListener(t, p) + srv.dialUpstream = func(ctx context.Context, h string) (string, error) { + return fake.addr, nil + } + + var runtimeParams []map[string]string + if tt.applicationName != "" { + runtimeParams = append(runtimeParams, map[string]string{"application_name": tt.applicationName}) + } + conn, err := connectThroughGatekeeper(t, srv, caTrustPool(t, ca), + "ep-foo-123.aws.neon.tech", "app_rw", "appdb", "run-token", runtimeParams...) + if err != nil { + t.Fatalf("connect through gatekeeper: %v", err) + } + + closeCtx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if err := conn.Close(closeCtx); err != nil { + t.Errorf("Close: %v", err) + } + + var entries []RequestLogData + deadline := time.Now().Add(2 * time.Second) + for time.Now().Before(deadline) { + entries = cap.snapshot() + if len(entries) >= 1 { + break + } + time.Sleep(20 * time.Millisecond) + } + if len(entries) != 1 { + t.Fatalf("got %d log entries, want exactly 1", len(entries)) + } + if got := entries[0].ApplicationName; got != tt.wantLogged { + t.Errorf("ApplicationName = %q, want %q", got, tt.wantLogged) + } + + if got := fake.lastApplicationName(); got != tt.applicationName { + t.Errorf("upstream application_name = %q, want %q (capturing for the log must not alter what's forwarded)", got, tt.applicationName) + } + }) + } +} + +// TestPostgresDeniedConnectionLogsApplicationName verifies that a connection +// denied before it ever reaches the upstream (here: network policy denies +// the host) still carries the client's application_name in the audit log -- +// a denied connection must remain traceable back to its origin just like an +// allowed one. +func TestPostgresDeniedConnectionLogsApplicationName(t *testing.T) { + ca, err := generateCA() + if err != nil { + t.Fatalf("generateCA: %v", err) + } + p := NewProxy() + p.SetCA(ca) + p.SetAuthToken("run-token") + p.SetNetworkPolicy("strict", []string{"api.github.com"}, nil) + p.SetPostgresResolver("*.neon.tech", NewStaticPostgresResolver("real-password")) + cap := &logCapture{} + p.SetLogger(cap.log) + + srv := newTestPostgresListener(t, p) + + msg, conn := pgClientHandshake(t, srv.Addr(), "ep-foo.aws.neon.tech", caTrustPool(t, ca), + "app_rw", "appdb", "run-token", map[string]string{"application_name": "box-abc123"}) + defer conn.Close() + + if _, ok := msg.(*pgproto3.ErrorResponse); !ok { + t.Fatalf("expected ErrorResponse (policy denial), got %T", msg) + } + + entries := cap.snapshot() + if len(entries) != 1 { + t.Fatalf("got %d log entries, want exactly 1", len(entries)) + } + if !entries[0].Denied { + t.Errorf("Denied = false, want true") + } + if got := entries[0].ApplicationName; got != "box-abc123" { + t.Errorf("ApplicationName = %q, want box-abc123 (denied connections must remain traceable)", got) + } +} + // flakyResolver returns the next password in a sequence on each // ResolvePassword call (clamped at the last entry) and records whether // InvalidatePassword was called. diff --git a/proxy/proxy.go b/proxy/proxy.go index 1c8e7eb..2d50163 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -49,6 +49,8 @@ import ( "sync" "sync/atomic" "time" + "unicode" + "unicode/utf8" keeplib "github.com/majorcontext/keep" "go.jetify.com/typeid" @@ -194,6 +196,15 @@ type RequestLogData struct { // TLS-terminated) connection carrying the individual inner requests. For // postgres connections it is the TCP peer of the data-plane listener. ClientAddr string + + // ApplicationName is the client-supplied Postgres "application_name" + // startup parameter, captured for request tracing. It is free-form, + // client-controlled text (sanitized before being placed here — see + // SanitizeLogValue) and, unlike RunID, is a correlation slug rather than + // a trusted identity: a client can set it to anything, including another + // caller's label. Empty for non-postgres connections and for postgres + // connections whose client did not set it. + ApplicationName string } // RequestLogger is called for each proxied request. @@ -809,6 +820,41 @@ func ValidateCaptureHeaders(headers []string) error { return nil } +// maxCapturedLogValueLen bounds how many bytes of a client-controlled string +// are kept in a request log entry. +const maxCapturedLogValueLen = 256 + +// SanitizeLogValue prepares a client-controlled string for inclusion in a +// structured log line: it discards invalid UTF-8, strips control characters +// (newlines, carriage returns, NUL, tabs, ...) so the value cannot forge +// additional log lines or otherwise corrupt structured log output, and +// bounds the result to maxCapturedLogValueLen bytes, truncating at a valid +// UTF-8 boundary rather than splitting a multi-byte rune. Used for both +// captured HTTP header values (capture_headers) and the Postgres +// application_name startup parameter — both are free-form text supplied by +// the client, not constrained by any protocol grammar the way most other +// logged fields are. +func SanitizeLogValue(s string) string { + if !utf8.ValidString(s) { + s = strings.ToValidUTF8(s, "") + } + if strings.ContainsFunc(s, unicode.IsControl) { + s = strings.Map(func(r rune) rune { + if unicode.IsControl(r) { + return -1 + } + return r + }, s) + } + if len(s) > maxCapturedLogValueLen { + s = s[:maxCapturedLogValueLen] + for len(s) > 0 && !utf8.ValidString(s) { + s = s[:len(s)-1] + } + } + return s +} + // ResolveContext looks up per-run context data by auth token. // Returns nil, false when no resolver is set or the token is not found. func (p *Proxy) ResolveContext(token string) (*RunContextData, bool) { diff --git a/proxy/proxy_test.go b/proxy/proxy_test.go index 977238d..a82c77c 100644 --- a/proxy/proxy_test.go +++ b/proxy/proxy_test.go @@ -20,6 +20,7 @@ import ( "sync/atomic" "testing" "time" + "unicode/utf8" ) func TestProxy_ForwardsRequests(t *testing.T) { @@ -4069,6 +4070,55 @@ func TestProxy_CaptureHeaders_StrippedBeforeForwarding(t *testing.T) { } } +// TestSanitizeLogValue exercises SanitizeLogValue, the shared helper used to +// bound and clean client-controlled strings (captured HTTP header values and +// the Postgres application_name startup parameter) before they reach a log +// line. Control characters must be stripped -- a raw newline or carriage +// return in a client-supplied value could otherwise forge additional log +// lines (log injection) in a text-formatted log. +func TestSanitizeLogValue(t *testing.T) { + tests := []struct { + name string + in string + want string + }{ + {"empty", "", ""}, + {"plain", "box-abc123", "box-abc123"}, + { + name: "strips embedded newline and carriage return", + in: "box-abc123\nrun_id=fake-admin-run\r", + want: "box-abc123run_id=fake-admin-run", + }, + { + name: "strips embedded NUL", + in: "box-abc\x00123", + want: "box-abc123", + }, + { + name: "truncates to the bound at a valid UTF-8 boundary", + in: strings.Repeat("a", maxCapturedLogValueLen+10), + want: strings.Repeat("a", maxCapturedLogValueLen), + }, + { + name: "truncates multi-byte UTF-8 without splitting a rune", + // Each "é" is 2 bytes; 200 of them is 400 bytes, well past the + // 256-byte bound, and the bound (256) falls in the middle of a rune. + in: strings.Repeat("é", 200), + want: strings.Repeat("é", maxCapturedLogValueLen/2), + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := SanitizeLogValue(tt.in); got != tt.want { + t.Errorf("SanitizeLogValue(%q) = %q, want %q", tt.in, got, tt.want) + } + if !utf8.ValidString(SanitizeLogValue(tt.in)) { + t.Errorf("SanitizeLogValue(%q) produced invalid UTF-8", tt.in) + } + }) + } +} + func TestProxy_CaptureHeaders_AvailableInLogData(t *testing.T) { backend := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK)