Skip to content

fix(postgres): surface upstream Postgres errors and log run-token auth failures#54

Merged
andybons merged 4 commits into
mainfrom
improve-postgres-logging
Jul 15, 2026
Merged

fix(postgres): surface upstream Postgres errors and log run-token auth failures#54
andybons merged 4 commits into
mainfrom
improve-postgres-logging

Conversation

@andybons

Copy link
Copy Markdown
Contributor

Problem

Discovered while debugging a Neon connectivity failure: the Postgres data plane collapses distinct root causes into one opaque signal.

  1. Upstream errors were flattened. When Neon rejected a connection with a Postgres wire ErrorResponse, gatekeeper discarded the server's Message and collapsed everything to the internal errUpstreamAuthFailed sentinel — so an IP-allowlist denial and a 28P01 invalid_password were indistinguishable in the log, and the actual reason never appeared.
  2. Run-token auth failures were silent. A client whose run token didn't match got 28P01 and produced zero server-side log output — invisible to any dashboard or log search.

Fix

  • upstreamErrorResponse now folds the upstream server's Severity / Code / Message into the error text (the upstream server's fields — never a credential), so the existing DEBUG postgres upstream connection failed line carries the real reason. An allowlist rejection now reads e.g. upstream error FATAL 08004: ... IP address ... is not authorized for this endpoint.
  • Auth-failure SQLSTATEs (28P01, 28000) still wrap errUpstreamAuthFailed via %w, so connectWithRetry's invalidate-and-retry-once behavior is unchanged; non-auth codes (like 08004) correctly don't trigger a pointless password invalidation.
  • Added a stage attribute (upstream_auth vs upstream_connect) to distinguish auth rejections from dial/TLS failures.
  • Run-token auth failure now logs a WARN line (visible without DEBUG) naming client address + SNI host — never the token.

Net: the run-token, network-policy, credential-resolution, and upstream-connect boundaries are now each independently identifiable in the logs.

Security

No credential can reach a log: Detail/Hint are deliberately excluded (only Severity/Code/Message), SCRAM client errors are deliberately left unwrapped (they embed username+password), the resolver path logs status codes and identifiers only, and the run-token WARN carries no token. Verified by grep + independent review.

Tests

Test-first, all three mutation-checked (reverting the fix / neutering the WARN each flips a test red), encoding real incident values (28P01, 08004, a concrete allowlist message). go test -race ./..., vet, gofmt clean.

CHANGELOG v0.17.3.

andybons added 2 commits July 15, 2026 12:32
…h failures

Two Postgres data-plane diagnosability gaps, closed without changing what
the client ever sees (still the generic "could not authenticate to
upstream database" — the underlying detail could echo the upstream
server's identifiers):

- upstreamErrorResponse collapsed every upstream ErrorResponse to either
  the bare errUpstreamAuthFailed sentinel or "upstream error (SQLSTATE
  %s)", discarding the upstream server's own Message. An IP-allowlist
  rejection and a bad password were indistinguishable in the DEBUG log,
  and the message text was never logged at all. It now folds the
  upstream's Severity, Code, and Message into the error text — these are
  the upstream SERVER's own error fields, never a credential — so the
  existing DEBUG "postgres upstream connection failed" line carries the
  real reason. Auth-failure SQLSTATEs (28P01, 28000) still wrap
  errUpstreamAuthFailed via %w, so connectWithRetry's errors.Is check and
  its invalidate-and-retry-once behavior are unchanged. That log line also
  gained a stage attribute (upstream_auth vs upstream_connect).

- A client whose run token failed authentication produced zero log output
  server-side. handleConn now logs a WARN-level line naming the client
  address and SNI host (stage=run_token_auth) — visible without DEBUG,
  never logging the token itself.

Grepped the diff to confirm no credential/token/password value can reach a
log call.
@claude

claude Bot commented Jul 15, 2026

Copy link
Copy Markdown
Contributor
📦 Previous Review (superseded by newer review)

Claude finished @andybons's task in 3m 49s —— View job


Reviewing PR #54

  • Gather context (PR diff, changed files)
  • Read proxy/postgres.go changes
  • Read test changes (proxy/postgres_test.go, proxy/pgtest_test.go)
  • Review for security issues (credential leaks, TLS, TOCTOU)
  • Review for race conditions / concurrency issues
  • Review for bugs, logic errors, error-handling gaps
  • Post inline comments for specific issues found
  • Post summary

Summary

This is a well-scoped, well-reasoned change. It only touches the error-detail path (upstreamErrorResponse, proxy/postgres.go:353-369) and adds one new WARN log line for run-token failures (handleConn, proxy/postgres.go:646-657) — no changes to auth logic, TLS config, credential resolution, or the relay itself.

Security review:

  • The upstream ErrorResponse.Message now flows into the DEBUG log (upstreamErrorResponse) — confirmed only Severity/Code/Message are used, never Detail/Hint. Since the upstream endpoint is TLS-verified before this data is trusted, and slog's text handler quotes/escapes control characters, this isn't a log-injection or credential-leak vector.
  • Confirmed the enriched error only reaches the DEBUG slog line — never the client-facing message (deny(502, "28P01", "could not authenticate to upstream database", ...) is unchanged) and never the audit RequestLogData/DenyReason fields, nor any OTel span (postgres.go emits no spans directly).
  • The new run-token-failure WARN (proxy/postgres.go:650-654) logs client_addr and host only — verified the run token itself never appears, matching the test assertion (TestPostgresRunTokenAuthFailureIsLogged).
  • sniHost is guaranteed non-empty at the WARN call site (the earlier empty-SNI branch already returned), so no zero-value surprises there.
  • errUpstreamAuthFailed sentinel wrapping via %w is preserved for 28P01/28000, so connectWithRetry's errors.Is check and its invalidate-and-retry-once behavior are intact — verified no accidental double-wrap or string-based matching was introduced.

Concurrency: No new shared mutable state; the WARN log and enriched error are constructed and logged synchronously within existing per-connection goroutines. Test helpers (syncBuffer, captureSlogText) correctly mutex-guard the buffer and mutate the global slog default only within a package that has no t.Parallel() tests, so no cross-test race.

One finding posted inline (proxy/postgres.go:770-776): the comment describing the stage attribute claims it distinguishes a credential-resolution failure from an upstream connect/SCRAM failure, but the code only produces two values — a resolver.ResolvePassword failure (e.g. the Neon API) lands in the same stage=upstream_connect bucket as a dial/TLS failure, not its own category. Minor/non-blocking, but worth fixing since precise log semantics is the whole point of this PR; the CHANGELOG's two-value description is actually the accurate one.

Tests: Read through TestUpstreamErrorResponseAuthFailurePreservesSentinelAndDetail, TestPostgresLogsUpstreamErrorResponseDetail, and TestPostgresRunTokenAuthFailureIsLogged — they exercise exactly the scenarios described in the PR body (sentinel preservation, non-auth SQLSTATE detail surfacing, run-token WARN) and each explicitly asserts credentials/tokens are absent from the log output. Test-first/mutation-checking claim is plausible given the structure; I did not independently re-run the mutation check.

Note: I was unable to run go build, go vet, or go test -race ./... in this environment — the sandboxed Bash tool required interactive approval that wasn't available in this run. If CI hasn't already confirmed a clean build/vet/test pass, that should be verified before merge.

Comment thread proxy/postgres.go Outdated
PR #54 review found the stage attribute on the "postgres upstream
connection failed" log produced only upstream_auth and upstream_connect.
A credential-resolution failure (resolver.ResolvePassword, wrapped as
"resolving postgres password: %w" in connectWithRetry) is not
errUpstreamAuthFailed, so it fell into stage=upstream_connect — the same
bucket as a real dial/TLS/SCRAM failure. An operator filtering by stage
could not tell a Neon API resolution failure (missing project, wrong
scope) apart from a network/TLS failure to the endpoint, which was the
whole point of the stage attribute.

Introduce an errResolvePassword sentinel, wrap the resolver failure with
it (alongside the existing human-readable "resolving postgres password:"
text), and classify it as stage=resolve via errors.Is before the generic
upstream_connect fallback. Only errUpstreamAuthFailed still drives
connectWithRetry's invalidate-and-retry, so a resolver failure never
invalidates a cached password. Doc comment updated to name all three
stages.
@claude

claude Bot commented Jul 15, 2026

Copy link
Copy Markdown
Contributor
📦 Previous Review (superseded by newer review)

Claude finished @andybons's task in 1m 27s —— View job


Reviewing PR #54 (new commit pushed)

  • Gather context (PR diff, new commits since previous review)
  • Review 90415d2 — does it address the stage comment/behavior mismatch flagged previously?
  • Re-review full diff for security/race/logic issues
  • Post findings / summary

Summary

The new commit (90415d2) directly and correctly addresses the finding from my previous review.

Previous finding, now fixed: stage previously only ever produced upstream_auth or upstream_connect, so a credential-resolution failure (resolver.ResolvePassword erroring, e.g. a Neon API failure) was indistinguishable from a real dial/TLS/SCRAM failure — despite the doc comment claiming otherwise.

The fix:

  • Introduces a new sentinel errResolvePassword (proxy/postgres.go:52-58).
  • connectWithRetry now wraps resolver failures with two %w verbs — fmt.Errorf("resolving postgres password: %w: %w", errResolvePassword, err) (proxy/postgres.go:856-860) — preserving both the classifiable sentinel and the human-readable resolver error. Go 1.20+ supports multiple %w verbs in one format string, and this repo requires Go 1.25.5 (go.mod), so this is valid.
  • serveAuthenticated now classifies via a switch/errors.Is before falling back to upstream_connect (proxy/postgres.go:788-794), giving three distinct, correctly-ordered stage values: resolve, upstream_auth, upstream_connect.
  • Critically, only errUpstreamAuthFailed still drives connectWithRetry's invalidate-and-retry path — errResolvePassword does not — so a resolver failure (e.g., Neon API misconfiguration) can no longer trigger a pointless cached-password invalidation. This is verified by the new TestPostgresLogsResolveStage test, which asserts both stage=resolve in the log and that InvalidatePassword was never called on a failingResolver.
  • The doc comment above the stage assignment and the CHANGELOG entry were both updated to accurately describe all three stages — the CHANGELOG previously undersold the fix (two stages) and now matches the code.

I verified this reasoning against the diff directly (git show 90415d2) rather than just the commit message, and it holds up: the sentinel wrapping order, the errors.Is classification order, and the retry-path exclusion are all correct and match the new test's assertions.

No new issues found. The change is narrowly scoped to the stage-classification path, doesn't touch TLS/auth/credential-injection logic, and doesn't introduce new shared mutable state. CI (go build, go vet, go test -race ./...) is green on this commit.

Note: As in my previous pass, I could not execute go build/go vet/go test directly in this sandboxed environment (Bash requires interactive approval unavailable here) — I instead confirmed via the repo's own CI status, which shows the CI workflow completed successfully on this commit.

@claude

claude Bot commented Jul 15, 2026

Copy link
Copy Markdown
Contributor

Claude finished @andybons's task in 1m 54s —— View job


Reviewing PR #54 (new commit pushed)

  • Gather context (PR diff, new commits since previous review)
  • Re-review full diff for security/race/logic issues, focused on 90415d2
  • Post findings / summary

Summary

90415d2 correctly resolves the one finding from my earlier pass on this PR.

Previous finding, now fixed: stage used to produce only two values (upstream_auth / upstream_connect), so a credential-resolution failure (e.g. the Neon API erroring) was indistinguishable from a real dial/TLS/SCRAM failure, despite the doc comment claiming otherwise.

Verified in the current diff (proxy/postgres.go):

  • New sentinel errResolvePassword (line 52), distinct from errUpstreamAuthFailed.
  • connectWithRetry's resolver-failure path (line 887) wraps it: fmt.Errorf("resolving postgres password: %w: %w", errResolvePassword, err). Two %w verbs in one format string is valid as of Go 1.20+, and this module requires Go 1.25.5 (go.mod), so that's fine.
  • serveAuthenticated (lines 815-821) now classifies via an ordered switch/errors.Is, producing three distinct stages: resolve, upstream_auth, upstream_connect.
  • Confirmed the important invariant holds: only errUpstreamAuthFailed still drives connectWithRetry's invalidate-and-retry (line 907's errors.Is check) — errResolvePassword does not satisfy it, so a resolver failure can never trigger a pointless cached-password invalidation. TestPostgresLogsResolveStage exercises exactly this with a failingResolver that records whether InvalidatePassword was called, and asserts it wasn't.
  • Doc comment (lines 805-814) and the CHANGELOG entry now both accurately describe all three stages.

Re-checked the rest of the diff for regressions:

  • Client-facing message is unchanged and still generic (deny(502, "28P01", "could not authenticate to upstream database", ...), line 828) regardless of stage — the richer detail only ever reaches the server-side DEBUG log.
  • upstreamErrorResponse (line 398) still wraps errUpstreamAuthFailed via %w only for auth-failure SQLSTATEs; non-auth codes get an unwrapped errors.New(detail), so they can never accidentally satisfy errors.Is(err, errUpstreamAuthFailed).
  • The run-token WARN (handleConn, lines 683-689) still only logs client_addr and host — no token — and sniHost is guaranteed non-empty at that point (the empty-SNI branch at line 639 already returns).
  • No new shared mutable state; nothing here changes concurrency behavior.

No new issues found. This is a narrowly-scoped, correct fix for the one thing I flagged. CI (CI workflow) is green on the current commit (e47fb2a).

Note: As in my previous passes, I could not execute go build/go vet/go test directly in this sandboxed environment (Bash requires interactive approval unavailable here) — confirmed via the repo's own CI status instead, which shows CI completed successfully on this commit.

@andybons andybons merged commit 3b1e0fd into main Jul 15, 2026
2 checks passed
@andybons andybons deleted the improve-postgres-logging branch July 15, 2026 16:54
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant