Repository navigation
Fix logging path that panics a connection task and wedges the proxy (#21) - #23
Conversation
) pgvpd logged to stdout via tracing_subscriber::fmt, and a per-connection info! ("tenant connection", early in handshake) wrote directly on the connection task — logging was on the data path. When a parent process closed BOTH pgvpd's stdout and stderr while pgvpd kept running (a launcher that exited right after spawn, or a supervisor that stopped draining piped stdio), the stdout write failed with EPIPE, tracing-subscriber's error fallback eprintln!'d to the now-closed stderr, and eprintln! panics on a write error. That panic unwound out of the info! call inside the spawned per-connection task, so the task died before Metrics::dec(connections_active) and before checkout. Every subsequent connection was then accepted and dropped ("Connection terminated unexpectedly"), connections_active climbed and never fell, and pool checkouts/creates froze — a permanent wedge (TCP still accepting, /status still serving, process alive) cleared only by restart. Pre-existing (1.0.0-1.0.4). This is the wedge behind the original field report; #20 (fixed in 1.0.4) was a separate slot-accounting leak. Fix: log through tracing_appender::non_blocking — a bounded channel drained by a dedicated worker thread (lossy: drops lines when full). The connection tasks only push to the channel; the worker does the actual write, so a slow or closed consumer can neither block nor panic a connection task. The startup banner and the fatal-error line now use non-panicking writes (writeln! to stderr, error ignored) instead of eprintln!. Regression coverage (Suite 10, tests/drizzle/log-wedge.mjs): spawn pgvpd with piped stdout+stderr, warm up, destroy both pipes, then assert connections still succeed and connections_active does not leak. Verified red on 1.0.4 (9/9 post-close connects "terminated unexpectedly", active leaked to 9) and green after (9/9 ok, active 0). Bump version to 1.0.5.
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
The harness used a fixed 1000ms sleep before probing the spawned pgvpd, which raced its startup on slow/cold CI runners (ECONNREFUSED before the pipe close → false setup failure). Poll the proxy port until it accepts, up to 20s, and loosen the active-leak threshold with a settle delay so a connection mid-close does not false-fail. No change to the fix or the assertions' intent.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 139577a7e1
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| name = "time" | ||
| version = "0.3.55" |
There was a problem hiding this comment.
Keep the dependency compatible with the Docker toolchain
The newly locked time 0.3.55 requires a Rust compiler newer than 1.85, but the checked-in Docker build still uses rust:1.85-slim (Dockerfile:1) and runs cargo build --release. Consequently, every build of the provided Dockerfile now fails Cargo's rust-version check before compiling; upgrade the builder toolchain or resolve tracing-appender/time to versions compatible with Rust 1.85.
Useful? React with 👍 / 👎.
…iagnostics Suite 10 failed on CI with 'proxy never came up' while passing locally — the harness spawned pgvpd on 16432/16433, the same ports the prior suite used, and on the CI runner the port was not always released in time, so the harness's pgvpd failed to bind and exited. Use dedicated ports (16442/16443, overridable) so the suite can't race another suite's pgvpd, and capture the child's stderr and spawn errors so a startup failure is visible instead of a bare timeout.
Root cause of the CI-only 'proxy never came up' failure: the harness built the child pgvpd's env by spreading process.env, and run.sh passed PGVPD_HOST=$PG_HOST as the upstream host — but PGVPD_HOST is pgvpd's own LISTEN host. On CI PG_HOST is 'localhost', so the child listened on localhost (::1 on the runner) while the harness probed 127.0.0.1 (IPv4); locally PG_HOST was 127.0.0.1 so it passed. Set PGVPD_HOST='127.0.0.1' explicitly in the child env (listen host), and pass the upstream host/port under non-colliding names (WEDGE_UP_HOST/WEDGE_UP_PORT), normalizing 'localhost' to 127.0.0.1 to avoid the IPv4/IPv6 mismatch. Verified by reproducing the CI env locally (leaked PGVPD_HOST=localhost) — now green.
Fixes #21. Release 1.0.5 (#21 only; #15/#14 follow).
The defect
Logging was on the connection data path. pgvpd logs to stdout via
tracing_subscriber::fmt, and a per-connectioninfo!("tenant connection", early in the handshake) wrote directly on the connection task. When a parent process closed both pgvpd's stdout and stderr while pgvpd kept running (a launcher that exited right after spawn, or a supervisor that stopped draining piped stdio), the stdout write failed with EPIPE, tracing-subscriber's error fallbackeprintln!'d to the now-closed stderr, andeprintln!panics on a write error. That panic unwound out of theinfo!call inside the spawned per-connection task, so the task died beforeMetrics::dec(connections_active)and before checkout. Every later connection was then accepted and dropped (Connection terminated unexpectedly),connections_activeclimbed and never fell, and pool checkouts froze — a permanent wedge (TCP still accepting,/statusstill serving, process alive) cleared only by restart.Pre-existing (1.0.0–1.0.4). This is the wedge behind the original field report; #20 (fixed in 1.0.4) was a separate slot-accounting leak.
The fix
Log through
tracing_appender::non_blocking— a bounded channel drained by a dedicated worker thread (lossy: drops lines when full). Connection tasks only push to the channel; the worker does the actual write, so a slow or closed consumer can neither block nor panic a connection task. The startup banner and fatal-error line use non-panicking writes.Verification
cargo fmt --check,cargo clippy -- -D warnings,cargo test(94 unit tests) — green../tests/run.sh53/53, including new Suite 10: spawn pgvpd with piped stdout+stderr, warm up, destroy both pipes, then assert connections still succeed andconnections_activedoes not leak.Bumps version to 1.0.5.