diff --git a/CHANGELOG.md b/CHANGELOG.md index f87a80f..8b7a362 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ Gatekeeper is pre-1.0. The configuration schema and credential source interface ## v0.17.3 — 2026-07-15 +### Changed + +- **Postgres data-plane failures now leave a legible server-side trail** — the client always receives the same generic `FATAL: could not authenticate to upstream database` for any failure past the run-token boundary, by design (the underlying error could echo the upstream server's identifiers), but two gaps meant the operator had no better signal server-side either. First, when the upstream (Neon) rejected a connection with a Postgres wire `ErrorResponse` — an IP-allowlist denial, `28P01 invalid_password`, or anything else — gatekeeper collapsed it to either the bare `errUpstreamAuthFailed` sentinel or `"upstream error (SQLSTATE %s)"`, discarding the upstream server's own `Message` entirely; an IP-allowlist rejection and a bad password were indistinguishable in the log, and the message text (the most useful part of any Postgres error) never appeared at all. `upstreamErrorResponse` now folds the upstream's `Severity`, `Code`, and `Message` — the upstream *server's* own error fields, never a credential — into the error text at every point gatekeeper reads an `ErrorResponse` from the upstream (`authenticateSCRAM`, `collectPostAuthFrames`), so the existing DEBUG `postgres upstream connection failed` line now carries the real reason. Authentication-failure SQLSTATEs (`28P01`, `28000`) still wrap `errUpstreamAuthFailed` via `%w`, so `connectWithRetry`'s `errors.Is` check and its invalidate-cached-password-and-retry-once behavior are unaffected — only the message the sentinel carries got richer. That log line also gained a `stage` attribute naming which of three failure boundaries the error came from — `resolve` (the credential resolver, e.g. the Neon API, failed before the proxy reached the upstream: missing project, wrong scope, API error), `upstream_auth` (the upstream server rejected the presented credential), and `upstream_connect` (a dial/TLS/SCRAM/protocol failure reaching the upstream) — so a resolution failure, an auth rejection, and a network/TLS failure are each independently filterable rather than collapsed together. Each stage is classified from a wrapped sentinel via `errors.Is` (`errResolvePassword`, `errUpstreamAuthFailed`), not a string prefix; only `errUpstreamAuthFailed` drives `connectWithRetry`'s invalidate-and-retry, so a resolver failure never needlessly invalidates a cached password. Second, a client whose run token failed to authenticate produced zero log output server-side — the `handleConn` boundary just sent `28P01` and returned; a failed connection there was invisible to any dashboard or log search. It now logs a `WARN`-level `postgres run-token authentication failed` line (visible without enabling DEBUG) naming the client address and the SNI host — never the token itself, not even a prefix. Between this and the network-policy denial (already logged at `WARN` via the policy logger), the run-token, network-policy, credential-resolution, and upstream-connect boundaries are now each independently identifiable in the logs + ### Fixed - **A portless `network.allow` pattern denied every Postgres data-plane connection under strict policy — including the shipped example** — `hostPattern.port == 0` (an unspecified pattern port) is documented and enforced by `matchesPattern` as "match only ports 80 and 443," an HTTP-scheme assumption. The Postgres data plane's policy check (`serveAuthenticated`, `proxy/postgres.go`) called that same HTTP-oriented `matchHost`/`checkNetworkPolicy` with the literal Postgres port (5432), so a pattern like `*.neon.tech` — which matches neither 80 nor 443 — could never match a live Postgres connection: every connection was denied with `FATAL: connection not allowed by network policy` (SQLSTATE 28000), regardless of how the allow list was written. This left the network-policy matcher inconsistent with the credential-resolver matcher for the identical connection: `postgresResolverFromEntries` already defaults an unspecified pattern port to 5432 when matching Postgres credential resolvers, so a host could be accepted for credential resolution and simultaneously rejected by policy. `examples/gatekeeper-postgres.yaml` and `docs/content/guides/13-postgres-neon.md` both document exactly this configuration (`policy: strict` + `allow: ["*.neon.tech"]`), so the shipped example was broken as written. Fixed by giving the Postgres data plane its own matcher, `matchHostPostgres` (`proxy/postgres.go`), and a corresponding `Proxy.checkNetworkPolicyPostgres` — both mirror the existing HTTP-facing functions exactly, but apply the same port-0-defaults-to-5432 override `postgresResolverFromEntries` already uses, so the two matchers can no longer disagree about the same connection. `matchHost`, `matchesPattern`, `checkNetworkPolicy`, and `checkNetworkPolicyForRequest` — the shared matcher and its HTTP/CONNECT callers — are untouched: a portless allow pattern still means "ports 80 and 443 only" for HTTP traffic, and an allow pattern pinned to an explicit non-5432 port still denies Postgres connections, exactly as before diff --git a/proxy/pgtest_test.go b/proxy/pgtest_test.go index 01c43e1..48302fd 100644 --- a/proxy/pgtest_test.go +++ b/proxy/pgtest_test.go @@ -91,6 +91,10 @@ type fakePostgresServer struct { // ErrorResponse with this SQLSTATE instead of AuthenticationOk after a // successful SCRAM exchange. Used to exercise non-auth upstream errors. failPostAuthWith string + // failPostAuthMessage is the ErrorResponse Message sent alongside + // failPostAuthWith. Defaults to a generic placeholder; tests that need to + // assert the message is surfaced in gatekeeper's logs set it explicitly. + failPostAuthMessage string mu sync.Mutex authOK int @@ -110,7 +114,18 @@ func withAuthMechanisms(mechs ...string) fakePostgresOption { // withFailPostAuth makes the fake send a FATAL ErrorResponse with the given // SQLSTATE instead of AuthenticationOk once SCRAM succeeds. func withFailPostAuth(sqlState string) fakePostgresOption { - return func(f *fakePostgresServer) { f.failPostAuthWith = sqlState } + return withFailPostAuthMessage(sqlState, "simulated post-auth failure") +} + +// withFailPostAuthMessage is like withFailPostAuth but also sets the +// ErrorResponse Message, letting a test assert that gatekeeper surfaces the +// upstream server's specific rejection reason (e.g. an IP-allowlist denial) +// rather than a flattened, message-less error. +func withFailPostAuthMessage(sqlState, message string) fakePostgresOption { + return func(f *fakePostgresServer) { + f.failPostAuthWith = sqlState + f.failPostAuthMessage = message + } } func (f *fakePostgresServer) counts() (authOK, authFail int) { @@ -240,7 +255,7 @@ func (f *fakePostgresServer) handle(conn net.Conn) { backend.Send(&pgproto3.ErrorResponse{ Severity: "FATAL", Code: f.failPostAuthWith, - Message: "simulated post-auth failure", + Message: f.failPostAuthMessage, }) backend.Flush() return diff --git a/proxy/postgres.go b/proxy/postgres.go index a710328..b3ad7f1 100644 --- a/proxy/postgres.go +++ b/proxy/postgres.go @@ -49,6 +49,14 @@ const postgresDialTimeout = 10 * time.Second // credentials the proxy presented (bad password or unknown role). var errUpstreamAuthFailed = errors.New("upstream authentication failed") +// errResolvePassword indicates the credential resolver (e.g. the Neon API) +// failed to produce an upstream password — the proxy never reached the +// upstream server. It is deliberately distinct from errUpstreamAuthFailed so +// the connect path can classify the failure stage in logs and, crucially, so +// a resolution failure never triggers the invalidate-cached-password-and-retry +// path reserved for an actual upstream credential rejection. +var errResolvePassword = errors.New("resolve upstream password failed") + // PostgresCredentialResolver resolves a Postgres password for a specific // upstream host, role, and database at connection time. Implementations // must never log password values. @@ -378,13 +386,21 @@ func collectPostAuthFrames(frontend *pgproto3.Frontend) ([][]byte, error) { } // upstreamErrorResponse maps an upstream ErrorResponse to a proxy error. -// Authentication-failure SQLSTATEs map to errUpstreamAuthFailed; everything -// else reports the SQLSTATE code only (the message could echo identifiers). +// Authentication-failure SQLSTATEs wrap errUpstreamAuthFailed (so +// connectWithRetry's errors.Is check and its invalidate-and-retry-once +// behavior keep working) with the upstream's severity, SQLSTATE, and +// message attached; other SQLSTATEs get the same detail without the +// sentinel. These are the UPSTREAM SERVER's own error fields — safe to log, +// never a credential — and this is the only place gatekeeper preserves them +// instead of discarding them, so the resulting error is never returned to +// the client (see serveAuthenticated's sanitized "could not authenticate to +// upstream database" reply) but is logged in full server-side. func upstreamErrorResponse(e *pgproto3.ErrorResponse) error { + detail := fmt.Sprintf("upstream error %s %s: %s", e.Severity, e.Code, e.Message) if isAuthFailureCode(e.Code) { - return errUpstreamAuthFailed + return fmt.Errorf("%w: %s", errUpstreamAuthFailed, detail) } - return fmt.Errorf("upstream error (SQLSTATE %s)", e.Code) + return errors.New(detail) } // isAuthFailureCode reports whether code is a SQLSTATE that indicates an @@ -664,6 +680,13 @@ func (s *PostgresServer) handleConn(conn net.Conn) { rc, ok := s.authenticate(pw.Password) if !ok { + // The run token itself must never be logged, not even a prefix — only + // that authentication at this boundary failed, and where from. + slog.Warn("postgres run-token authentication failed", + "subsystem", "proxy", + "stage", "run_token_auth", + "client_addr", conn.RemoteAddr().String(), + "host", sniHost) sendPGError(backend, "28P01", "password authentication failed") return } @@ -780,10 +803,25 @@ func (s *PostgresServer) serveAuthenticated(ctx context.Context, clientConn net. up, grants, err := s.connectWithRetry(ctx, resolver, sniHost, user, database, startupParams) if err != nil { // Never include the underlying error in the client-facing message: it - // could echo the upstream server's identifiers. The full error is only - // logged at debug level, never with credential values. + // could echo the upstream server's identifiers. The full error — + // including the upstream server's own ErrorResponse fields when the + // failure came from there (see upstreamErrorResponse) — is only logged + // at debug level, never with credential values. stage names which of the + // three failure boundaries the error came from, so they are never + // conflated in the log: resolve (the credential resolver, e.g. the Neon + // API, failed before the proxy reached the upstream), upstream_auth (the + // upstream server rejected the presented credential), and upstream_connect + // (dial/TLS/SCRAM/protocol failure reaching the upstream). + stage := "upstream_connect" + switch { + case errors.Is(err, errUpstreamAuthFailed): + stage = "upstream_auth" + case errors.Is(err, errResolvePassword): + stage = "resolve" + } slog.Debug("postgres upstream connection failed", "subsystem", "proxy", + "stage", stage, "host", sniHost, "user", user, "error", err) @@ -842,7 +880,11 @@ func (s *PostgresServer) connectWithRetry(ctx context.Context, resolver Postgres connect := func() (*upstreamConn, error) { password, err := resolver.ResolvePassword(ctx, host, user, database) if err != nil { - return nil, fmt.Errorf("resolving postgres password: %w", err) + // Wrap both the errResolvePassword sentinel (so the connect path can + // classify this as stage=resolve via errors.Is, and so it is never + // mistaken for an upstream credential rejection that would invalidate + // and retry) and the human-readable context in one error. + return nil, fmt.Errorf("resolving postgres password: %w: %w", errResolvePassword, err) } return connectPostgresUpstream(ctx, upstreamParams{ dialAddr: dialAddr, diff --git a/proxy/postgres_test.go b/proxy/postgres_test.go index 8550809..206872c 100644 --- a/proxy/postgres_test.go +++ b/proxy/postgres_test.go @@ -1,6 +1,7 @@ package proxy import ( + "bytes" "context" "crypto/tls" "crypto/x509" @@ -694,6 +695,233 @@ func TestPostgresRetriesAfterStalePassword(t *testing.T) { } } +// syncBuffer is a concurrency-safe io.Writer for capturing slog output from +// goroutines under test (each Postgres connection is handled on its own +// goroutine). +type syncBuffer struct { + mu sync.Mutex + buf bytes.Buffer +} + +func (b *syncBuffer) Write(p []byte) (int, error) { + b.mu.Lock() + defer b.mu.Unlock() + return b.buf.Write(p) +} + +func (b *syncBuffer) String() string { + b.mu.Lock() + defer b.mu.Unlock() + return b.buf.String() +} + +// captureSlogText redirects the default slog logger, down to DEBUG, to a +// buffer for the duration of the test and returns it. The previous default +// logger is restored on cleanup. +func captureSlogText(t *testing.T) *syncBuffer { + t.Helper() + buf := &syncBuffer{} + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + return buf +} + +// waitForLogContaining polls buf until it contains want or two seconds +// elapse (the audit/diagnostic log line is written asynchronously, after the +// client already observes the connection failure), returning the final +// snapshot either way. +func waitForLogContaining(buf *syncBuffer, want string) string { + deadline := time.Now().Add(2 * time.Second) + var got string + for time.Now().Before(deadline) { + got = buf.String() + if strings.Contains(got, want) { + return got + } + time.Sleep(20 * time.Millisecond) + } + return got +} + +// TestUpstreamErrorResponseAuthFailurePreservesSentinelAndDetail is a +// regression guard for the errUpstreamAuthFailed sentinel: connectWithRetry +// decides whether to invalidate the cached password and retry via +// errors.Is(err, errUpstreamAuthFailed), so any enrichment of the error must +// keep that check working while also carrying the upstream SQLSTATE, instead +// of collapsing it to the bare sentinel with no detail. +func TestUpstreamErrorResponseAuthFailurePreservesSentinelAndDetail(t *testing.T) { + err := upstreamErrorResponse(&pgproto3.ErrorResponse{ + Severity: "FATAL", + Code: "28P01", + Message: "password authentication failed for user \"app_rw\"", + }) + if !errors.Is(err, errUpstreamAuthFailed) { + t.Fatalf("errors.Is(err, errUpstreamAuthFailed) = false, want true; err = %v", err) + } + if !strings.Contains(err.Error(), "28P01") { + t.Errorf("error text = %q, want it to contain SQLSTATE 28P01", err.Error()) + } +} + +// TestPostgresLogsUpstreamErrorResponseDetail drives an upstream rejection +// that is NOT an auth-failure SQLSTATE — the kind of thing an IP-allowlist +// check on the real Neon endpoint would send — and asserts the server-side +// diagnostic log carries the upstream SQLSTATE and message instead of the +// flattened, message-less error the proxy used to log. It also asserts the +// upstream password never reaches the log. +func TestPostgresLogsUpstreamErrorResponseDetail(t *testing.T) { + buf := captureSlogText(t) + + const rejectMessage = "connection rejected: IP address 203.0.113.5 is not authorized for this endpoint" + fake := startFakePostgres(t, "ep-foo-123.aws.neon.tech", "app_rw", "real-password", + withFailPostAuthMessage("08004", rejectMessage)) + + 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")) + + srv := newTestPostgresListener(t, p) + srv.dialUpstream = func(_ context.Context, _ string) (string, error) { + return fake.addr, nil + } + + conn, err := connectThroughGatekeeper(t, srv, caTrustPool(t, ca), + "ep-foo-123.aws.neon.tech", "app_rw", "appdb", "run-token") + if err == nil { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + conn.Close(ctx) + t.Fatal("connect succeeded, want the simulated upstream rejection to fail it") + } + + got := waitForLogContaining(buf, "08004") + if !strings.Contains(got, "08004") { + t.Fatalf("log output missing upstream SQLSTATE 08004; got:\n%s", got) + } + if !strings.Contains(got, rejectMessage) { + t.Fatalf("log output missing upstream error message %q; got:\n%s", rejectMessage, got) + } + if !strings.Contains(got, "upstream_connect") { + t.Errorf("log output missing stage=upstream_connect marker; got:\n%s", got) + } + if strings.Contains(got, "real-password") { + t.Fatalf("log output leaked the upstream password:\n%s", got) + } + if strings.Contains(got, "run-token") { + t.Fatalf("log output leaked the client run token:\n%s", got) + } +} + +// TestPostgresRunTokenAuthFailureIsLogged drives a client that fails +// run-token authentication and asserts a log line now names the boundary, +// the client address, and the SNI host — that failure used to be completely +// silent server-side. The run token value itself must never appear. +func TestPostgresRunTokenAuthFailureIsLogged(t *testing.T) { + buf := captureSlogText(t) + + p, ca := newTestProxyWithCA(t) + p.SetAuthToken("static-token") + srv := newTestPostgresListener(t, p) + + msg, conn := pgClientHandshake(t, srv.Addr(), "db.test.local", caTrustPool(t, ca), "app", "appdb", "wrong-token") + defer conn.Close() + + errResp, ok := msg.(*pgproto3.ErrorResponse) + if !ok { + t.Fatalf("expected ErrorResponse, got %T", msg) + } + if errResp.Code != "28P01" { + t.Errorf("ErrorResponse code = %q, want 28P01", errResp.Code) + } + + got := waitForLogContaining(buf, "run_token_auth") + if !strings.Contains(got, "run_token_auth") { + t.Fatalf("log output missing stage=run_token_auth marker; got:\n%s", got) + } + if !strings.Contains(got, "db.test.local") { + t.Fatalf("log output missing SNI host db.test.local; got:\n%s", got) + } + if !strings.Contains(got, "127.0.0.1") { + t.Fatalf("log output missing client address; got:\n%s", got) + } + if strings.Contains(got, "wrong-token") { + t.Fatalf("log output leaked the client's run token:\n%s", got) + } + if strings.Contains(got, "static-token") { + t.Fatalf("log output leaked the configured auth token:\n%s", got) + } +} + +// failingResolver always fails to resolve a password, standing in for a Neon +// API resolution failure (missing project, wrong scope, upstream API error). +// It records whether InvalidatePassword was called so a test can assert the +// upstream-auth retry/invalidate path is NOT taken for a resolver failure. +type failingResolver struct { + err error + invalidated atomic.Bool +} + +func (r *failingResolver) ResolvePassword(_ context.Context, _, _, _ string) (string, error) { + return "", r.err +} + +func (r *failingResolver) InvalidatePassword(_, _, _ string) { + r.invalidated.Store(true) +} + +// TestPostgresLogsResolveStage drives a credential-resolution failure (the +// resolver's ResolvePassword returns an error) and asserts the diagnostic log +// tags it stage=resolve — distinct from the upstream_connect bucket a real +// dial/TLS/SCRAM failure lands in — so an operator can tell a Neon API +// resolution failure apart from a network/TLS failure to the endpoint. It also +// asserts the resolver failure does NOT trigger the upstream-auth +// invalidate-and-retry path. +func TestPostgresLogsResolveStage(t *testing.T) { + buf := captureSlogText(t) + + ca, err := generateCA() + if err != nil { + t.Fatalf("generateCA: %v", err) + } + p := NewProxy() + p.SetCA(ca) + p.SetAuthToken("run-token") + failing := &failingResolver{err: errors.New("neon endpoint \"ep-foo-123\" not found in configured project")} + p.SetPostgresResolver("*.neon.tech", failing) + + srv := newTestPostgresListener(t, p) + + conn, err := connectThroughGatekeeper(t, srv, caTrustPool(t, ca), + "ep-foo-123.aws.neon.tech", "app_rw", "appdb", "run-token") + if err == nil { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + conn.Close(ctx) + t.Fatal("connect succeeded, want the resolver failure to fail it") + } + + got := waitForLogContaining(buf, "stage=resolve") + if !strings.Contains(got, "stage=resolve") { + t.Fatalf("log output missing stage=resolve marker; got:\n%s", got) + } + if !strings.Contains(got, "resolving postgres password") { + t.Errorf("log output missing human-readable resolver context; got:\n%s", got) + } + if strings.Contains(got, "stage=upstream_connect") { + t.Errorf("resolver failure misclassified as stage=upstream_connect; got:\n%s", got) + } + if failing.invalidated.Load() { + t.Error("resolver failure must not trigger the upstream-auth invalidate-and-retry path") + } +} + func TestPostgresPolicyDeniesHost(t *testing.T) { ca, err := generateCA() if err != nil {