Skip to content

Add login path observability: login_duration histogram, in-flight gauge, abandoned counter - #1471

Open
ryderhwang wants to merge 3 commits into
pgdogdev:mainfrom
ryderhwang:login-metrics
Open

Add login path observability: login_duration histogram, in-flight gauge, abandoned counter#1471
ryderhwang wants to merge 3 commits into
pgdogdev:mainfrom
ryderhwang:login-metrics

Conversation

@ryderhwang

Copy link
Copy Markdown
Contributor

Implements #1470 (context in #1469).

What

Four new series on the OpenMetrics endpoint:

  • logins_in_flight (gauge) — accepted but not yet ReadyForQuery; the leading indicator of login-path saturation
  • logins (counter) — completed logins
  • logins_abandoned (counter) — clients that started the Postgres handshake but went away (or hit client_login_timeout) before login completed
  • login_duration (histogram, ms) — accept → ReadyForQuery latency of completed logins

Design

  • A LoginTimer RAII guard is created at accept, engaged on the first startup message, success-marked when Client::spawn gets a logged-in client, and disarmed when PgDog ends the login with an explicit response (auth failure, shutting down, pool down) or the connection is a cancel request. Dropping it engaged-but-unfinished counts one abandoned login — every exit path is covered without instrumenting each error branch.
  • Bare TCP connect/close with no startup bytes (LB health checks, k8s TCP probes) is excluded from logins_abandoned — those never engage the guard.
  • Histogram rendering goes through a new overridable OpenMetric::render_measurements (default keeps today's behavior for every existing metric), emitting standard _bucket/_sum/_count with cumulative buckets. Buckets are 1ms–30s; happy to change bounds.
  • The three scalar metrics also flow through the OTLP exporter; the histogram is text-endpoint-only for now since the OTLP renderer currently only speaks gauge/sum.

Verification

  • 6 new unit tests (guard semantics incl. probe exclusion + histogram text rendering); cargo nextest run --profile dev shows an identical pass/fail set to current main on the same machine (all pre-existing/env failures, zero deltas).
  • Live smoke test against Postgres 14 with passthrough_auth = "enabled_plain_allow_change", transaction mode: a real psql login renders logins 1 + one histogram observation; a bare TCP connect/close renders nothing; a client that sends StartupMessage, receives AuthenticationCleartextPassword, and closes renders logins_abandoned 1.
  • cargo fmt + cargo clippy clean.

Why

During our worst production login-path saturation event (~130k client-side connect timeouts over ~30 min, details in #1469), every PgDog-side signal was green — TCP accepted, clients gave up mid-startup, and nothing was logged or counted. With these metrics the event is a one-glance diagnosis: logins_in_flight climbing with login_duration p99 stretching toward the clients' connect timeout, then logins_abandoned ticking up.

When the login path saturates, TCP accepts succeed but clients time out
mid-startup and PgDog reports nothing: no error, no log line, no metric.
Make that failure mode observable on the OpenMetrics endpoint:

- logins_in_flight: connections accepted but not yet ReadyForQuery,
  the leading indicator of login-path saturation
- logins: completed client logins
- logins_abandoned: clients that started the Postgres handshake but
  disconnected (or timed out) before login completed; connections that
  close without sending a single startup byte (load balancer TCP health
  checks) are excluded
- login_duration: accept-to-ReadyForQuery histogram (ms) for completed
  logins

A LoginTimer guard is created at accept, engaged on the first startup
message, marked successful when login completes, and disarmed when PgDog
ends the login with an explicit response (auth failure, shutdown, pool
down) or the connection is a cancel request. Dropping it engaged but
unfinished counts an abandoned login, so every exit path is covered
without touching each error branch.

The scalar metrics also flow through the OTLP exporter; the histogram is
rendered only on the OpenMetrics text endpoint via a new overridable
OpenMetric::render_measurements (the OTLP renderer currently only speaks
gauge/sum).

Closes pgdogdev#1470

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@codecov

codecov Bot commented Sep 1, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 98.93993% with 3 lines in your changes missing coverage. Please review.

Files with missing lines Patch % Lines
pgdog/src/stats/otel_exporter.rs 0.00% 2 Missing ⚠️
pgdog/src/frontend/listener.rs 92.85% 1 Missing ⚠️

📢 Thoughts on this report? Let us know!

@ryderhwang

Copy link
Copy Markdown
Contributor Author

Validated under load while benchmarking for #1469: with the harness driving 15,000 logins/s through a single instance (workers = 1), logins counted 119,068 — exactly matching the generator's success count, zero drift — and the histogram/abandoned/in-flight series behaved as designed (a mid-login client disconnect increments logins_abandoned; a bare TCP connect/close increments nothing).

One scope note from that investigation: these metrics see only connections PgDog has accepted. Kernel-level pre-accept drops (accept-queue overflow, conntrack) remain invisible by nature — listen_backlog (#1452) plus node TcpExtListenOverflows monitoring cover that side.

ryderhwang and others added 2 commits September 1, 2026 13:29
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The multiline writeln invocations left llvm-cov region artifacts on their
continuation lines; captured-identifier format strings keep each write on
one line and read cleaner.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@ryderhwang

Copy link
Copy Markdown
Contributor Author

Re the codecov report — the 3 uncovered patch lines are all in paths that have no coverage on main either, independent of this PR:

  • stats/otel_exporter.rs (2 lines): Logins::load() and all.extend(logins.iter()) inside the OTLP push loop. run() returns early when no otel.endpoint is configured, and no CI config sets one, so the whole loop body is at 0% on main (file is ~22% for that reason).
  • frontend/listener.rs (1 line): login_timer.engage() in the Startup::GssEnc arm. Nothing in the integration suites sends a GSSENCRequest, so the arm's existing SslReply::No line is equally uncovered on main. The engage()/success()/disarm() semantics are unit-tested in stats/logins.rs, and the SSL + plain-startup engage() calls, the Client::spawn hand-off, and the Cancel disarm() are exercised by the integration suites.

Happy to add a raw-socket GSSENC test or factor the exporter's collection step out into a testable fn if you'd like those covered, but I didn't want to restructure existing code for it in this PR.

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