From dc132071d5315bde0384d4f0a12e854fe5e20781 Mon Sep 17 00:00:00 2001 From: gsxdsm Date: Thu, 23 Jul 2026 09:13:21 -0700 Subject: [PATCH] fix(#2411): let embedded PostgreSQL crash recovery finish instead of racing it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit beta.4 follow-up from the issue thread: on an interrupted (not-cleanly-shut-down) cluster, the elevated Windows launcher declared readiness on a bare TCP accept while crash recovery still rejected every connection with 57P03, so ensureDatabase failed and the start cleanup fast-shutdown the recovering postmaster ~0.2s after launch; the retry then joined the instance it had just told to stop, got ECONNREFUSED, and parked the dashboard in a dead shell. The 30s ".pgrunner sharing violation" stall was recovery's SyncDataDirectory fsync walk hitting Fusion's own pgctl log inside the data dir. - Move the pgctl runner dir to a sibling .pgrunner- outside the data dir (and sweep the legacy in-dataDir .pgrunner), so recovery's fsync walk can never contend with the postmaster's inherited log handle. - Ignore 57P03 recovery rejections in the elevated readiness fatal scan. - Owned starts wait for the cluster to genuinely accept connections (retrying 57P03/socket errors, bounded by the start timeout) before ensureDatabase — never stop a postmaster that is still in recovery. - Join-path database verify retries the 57P03 recovery signal for up to 15s; socket errors keep the instant optimistic-join contract for stale pids. - startup-factory's joined-instance-unreachable retry backs off across ~15s instead of a single 500ms attempt. Co-Authored-By: Claude Fable 5 --- .changeset/embedded-pg-crash-recovery-2411.md | 7 + .../postgres/embedded-lifecycle.test.ts | 134 +++++++++++++++ .../embedded-windows-elevated.test.ts | 65 ++++++++ .../core/src/postgres/embedded-lifecycle.ts | 155 +++++++++++++++++- .../src/postgres/embedded-windows-elevated.ts | 58 ++++++- packages/core/src/postgres/startup-factory.ts | 68 ++++++-- 6 files changed, 458 insertions(+), 29 deletions(-) create mode 100644 .changeset/embedded-pg-crash-recovery-2411.md diff --git a/.changeset/embedded-pg-crash-recovery-2411.md b/.changeset/embedded-pg-crash-recovery-2411.md new file mode 100644 index 0000000000..7db7d6abc8 --- /dev/null +++ b/.changeset/embedded-pg-crash-recovery-2411.md @@ -0,0 +1,7 @@ +--- +"@runfusion/fusion": patch +--- + +summary: Fix embedded PostgreSQL crash-recovery boot on Windows — no self-shutdown race, no 30s .pgrunner log stall. +category: fix +dev: Issue #2411 (beta.4 follow-up). pgctl runner logs moved to a sibling `.pgrunner-` dir so crash recovery's data-dir fsync walk never hits them (legacy in-dataDir `.pgrunner` is swept); the elevated readiness scan ignores 57P03 recovery rejections; owned starts wait for the cluster to accept connections before ensureDatabase (bounded by the start timeout); the join verify retries 57P03 for up to 15s; startup-factory's joined-instance-unreachable retry backs off across ~15s instead of one 500ms attempt. diff --git a/packages/core/src/__tests__/postgres/embedded-lifecycle.test.ts b/packages/core/src/__tests__/postgres/embedded-lifecycle.test.ts index 1922ca9a1c..90bca02723 100644 --- a/packages/core/src/__tests__/postgres/embedded-lifecycle.test.ts +++ b/packages/core/src/__tests__/postgres/embedded-lifecycle.test.ts @@ -38,6 +38,8 @@ import { resolveEmbeddedMaxConnections, DEFAULT_EMBEDDED_MAX_CONNECTIONS, DEFAULT_EMBEDDED_MAX_CONNECTIONS_WIN32, + isClusterNotYetAcceptingError, + isClusterStartingUpError, isDataDirInitialized, isWindowsElevatedAdmin, normalizeMacosEmbeddedPostgresDylibSymlinks, @@ -965,6 +967,138 @@ describe("embedded-lifecycle: join-path database verify is best-effort", () => { }); }); +/* +FNXC:PostgresEmbedded 2026-07-23-10:40: +Issue #2411 (beta.4 follow-up): an interrupted cluster listens during crash +recovery but rejects every connection with 57P03 until redo completes. The +owned start must WAIT that out (never stop the recovering postmaster), and the +join path must retry the 57P03 signal — while socket-level failures keep the +instant optimistic-join contract (a stale pid file must not add a wait). +Mocked/stubbed, no real Postgres; runs under the gate/CI default. +*/ +describe("embedded-lifecycle: crash-recovery-aware connect classification (issue #2411)", () => { + it("classifies 57P03 / recovery messages as starting up", () => { + expect(isClusterStartingUpError({ code: "57P03" })).toBe(true); + expect(isClusterStartingUpError(new Error("FATAL: the database system is starting up"))).toBe(true); + expect(isClusterStartingUpError(new Error("the database system is in recovery mode"))).toBe(true); + expect(isClusterStartingUpError(new Error("connect ECONNREFUSED 127.0.0.1:5432"))).toBe(false); + expect(isClusterStartingUpError(new Error('password authentication failed for user "postgres"'))).toBe(false); + }); + + it("classifies socket-level failures as not-yet-accepting only for the owned wait superset", () => { + expect(isClusterNotYetAcceptingError({ code: "ECONNREFUSED" })).toBe(true); + expect(isClusterNotYetAcceptingError(new Error("connect ECONNREFUSED 127.0.0.1:52572"))).toBe(true); + expect(isClusterNotYetAcceptingError({ code: "CONNECT_TIMEOUT" })).toBe(true); + expect(isClusterNotYetAcceptingError({ code: "57P03" })).toBe(true); + expect(isClusterNotYetAcceptingError(new Error("syntax error at or near"))).toBe(false); + }); +}); + +describe("embedded-lifecycle: owned start waits out crash recovery (issue #2411)", () => { + it("retries 57P03 rejections until the cluster accepts, without stopping it", async () => { + vi.useFakeTimers(); + const logs: string[] = []; + const lifecycle = new EmbeddedPostgresLifecycle({ + dataDir: "/tmp/unused-recovery-wait", + database: "fusion", + startTimeoutMs: 30_000, + onLog: (message) => logs.push(message), + }); + let attempts = 0; + const internal = lifecycle as unknown as { + openMaintenanceSqlOn: (port: number) => unknown; + waitForClusterAcceptingConnections: (port: number, signal?: AbortSignal) => Promise; + }; + internal.openMaintenanceSqlOn = () => { + const sql = (() => { + attempts += 1; + if (attempts < 3) { + return Promise.reject( + Object.assign(new Error("the database system is starting up"), { code: "57P03" }), + ); + } + return Promise.resolve([{ one: 1 }]); + }) as unknown as { end: (opts?: unknown) => Promise }; + (sql as { end: (opts?: unknown) => Promise }).end = async () => {}; + return sql; + }; + + const wait = internal.waitForClusterAcceptingConnections(55490); + await vi.advanceTimersByTimeAsync(1_100); + await expect(wait).resolves.toBeUndefined(); + expect(attempts).toBe(3); + expect(logs.some((line) => /crash recovery may be in progress/i.test(line))).toBe(true); + }); + + it("surfaces a non-recovery error immediately", async () => { + const lifecycle = new EmbeddedPostgresLifecycle({ + dataDir: "/tmp/unused-recovery-fatal", + database: "fusion", + }); + const internal = lifecycle as unknown as { + openMaintenanceSqlOn: (port: number) => unknown; + waitForClusterAcceptingConnections: (port: number, signal?: AbortSignal) => Promise; + }; + internal.openMaintenanceSqlOn = () => { + const sql = (() => + Promise.reject(new Error('password authentication failed for user "postgres"'))) as unknown as { + end: (opts?: unknown) => Promise; + }; + (sql as { end: (opts?: unknown) => Promise }).end = async () => {}; + return sql; + }; + + await expect(internal.waitForClusterAcceptingConnections(55490)).rejects.toThrow( + /password authentication failed/i, + ); + }); +}); + +describe("embedded-lifecycle: join path retries crash recovery (issue #2411)", () => { + it("retries a 57P03-rejecting joined instance instead of giving up on the first probe", async () => { + vi.useFakeTimers(); + const dataDir = makeDataDir(); + writeFileSync(join(dataDir, "PG_VERSION"), "15\n"); + writeFileSync( + join(dataDir, "postmaster.pid"), + ["12345", dataDir, String(1784424901), "55446", "/tmp", "localhost", "5432101", "ready"].join("\n") + "\n", + ); + const logLines: string[] = []; + let attempts = 0; + const createDatabaseIfMissing = vi + .spyOn( + EmbeddedPostgresLifecycle.prototype as unknown as { + createDatabaseIfMissing: (port: number) => Promise; + }, + "createDatabaseIfMissing", + ) + .mockImplementation(async () => { + attempts += 1; + if (attempts < 3) { + throw Object.assign(new Error("the database system is starting up"), { code: "57P03" }); + } + }); + try { + const lifecycle = new EmbeddedPostgresLifecycle({ + ...baseOptions(dataDir), + onLog: (message) => logLines.push(message), + }); + + const start = lifecycle.start(); + await vi.advanceTimersByTimeAsync(1_100); + await expect(start).resolves.toMatchObject({ + runtimeUrl: expect.stringContaining(":55446/"), + }); + expect(attempts).toBe(3); + expect(logLines.some((line) => /not accepting connections yet/i.test(line))).toBe(true); + expect(logLines.some((line) => /could not verify database/i.test(line))).toBe(false); + } finally { + createDatabaseIfMissing.mockRestore(); + rmSync(dataDir, { recursive: true, force: true }); + } + }); +}); + describe("embedded-lifecycle: startup timeout (P1 #24)", () => { it("EmbeddedStartTimeoutError carries the timeout and data dir", () => { const err = new EmbeddedStartTimeoutError(5000, "/tmp/data"); diff --git a/packages/core/src/__tests__/postgres/embedded-windows-elevated.test.ts b/packages/core/src/__tests__/postgres/embedded-windows-elevated.test.ts index 655b19f234..06b35798e1 100644 --- a/packages/core/src/__tests__/postgres/embedded-windows-elevated.test.ts +++ b/packages/core/src/__tests__/postgres/embedded-windows-elevated.test.ts @@ -1,8 +1,11 @@ import { describe, expect, it } from "vitest"; +import { join, sep } from "node:path"; import { DEFAULT_EMBEDDED_POSTGRES_FLAGS } from "../../postgres/embedded-lifecycle.js"; import { buildPgCtlOptionsString, buildPgCtlStartArgs, + containsElevatedStartupFatal, + resolvePgRunnerDir, sanitizePostgresFlags, withWindowsNativeBinPath, WindowsPostgresFatalDetector, @@ -83,6 +86,68 @@ describe("Windows child PATH hardening", () => { }); }); +/* + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Issue #2411 (beta.4 follow-up): crash recovery on an interrupted cluster + * fsync-walks the ENTIRE data directory (SyncDataDirectory), so Fusion's pgctl + * runner log — whose write handle the postmaster inherits as its stderr — must + * live OUTSIDE the data dir. Keeping it inside produced the field-reported + * "could not open file ./.pgrunner/pgctl-.log: sharing violation … + * retrying for 30 seconds" stall on every crash recovery. + */ +describe("pg runner dir placement (issue #2411)", () => { + it("places the runner dir as a SIBLING of the data dir, never inside it", () => { + const dataDir = join("C:\\Users\\op", ".fusion", "embedded-postgres", "default"); + const runDir = resolvePgRunnerDir(dataDir); + + expect(runDir).toBe(join("C:\\Users\\op", ".fusion", "embedded-postgres", ".pgrunner-default")); + expect(runDir.startsWith(dataDir + sep)).toBe(false); + }); + + it("derives distinct sibling dirs for distinct data dirs (test clusters do not collide)", () => { + expect(resolvePgRunnerDir(join("/g", "embedded-postgres", "default"))).not.toBe( + resolvePgRunnerDir(join("/g", "embedded-postgres", "test")), + ); + }); + + it("tolerates a trailing path separator on the data dir", () => { + expect(resolvePgRunnerDir(join("/g", "embedded-postgres", "default") + sep)).toBe( + join("/g", "embedded-postgres", ".pgrunner-default"), + ); + }); +}); + +/* + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Issue #2411 (beta.4 follow-up): during crash recovery PostgreSQL listens but + * rejects clients with `FATAL: the database system is starting up` (57P03). + * The readiness poll's log scan treated that normal recovery progress as a + * startup failure and issued a fast-shutdown request ~0.2s into recovery — + * the self-shutdown race the reporter captured. Recovery-rejection lines must + * be ignored while genuine FATAL startup errors still trip the scan. + */ +describe("elevated startup fatal scan (issue #2411)", () => { + it("ignores crash-recovery client rejections", () => { + expect( + containsElevatedStartupFatal( + "LOG: database system was interrupted; last known up at 04:38:04\n" + + "FATAL: the database system is starting up\n" + + "FATAL: the database system is in recovery mode\n", + ), + ).toBe(false); + }); + + it("still trips on a genuine FATAL startup error", () => { + expect( + containsElevatedStartupFatal( + "FATAL: the database system is starting up\n" + + 'FATAL: could not bind IPv4 address "127.0.0.1": Address already in use\n', + ), + ).toBe(true); + expect(containsElevatedStartupFatal("PANIC: could not locate a valid checkpoint record\n")).toBe(true); + }); +}); + describe("pg_ctl elevated launch composition", () => { it("carries the port and sanitized flags in the -o option string", () => { expect(buildPgCtlOptionsString(55499, ["-c", "shared_memory_type=sysv"])).toBe( diff --git a/packages/core/src/postgres/embedded-lifecycle.ts b/packages/core/src/postgres/embedded-lifecycle.ts index 74a0074d70..2a9a14649e 100644 --- a/packages/core/src/postgres/embedded-lifecycle.ts +++ b/packages/core/src/postgres/embedded-lifecycle.ts @@ -1068,6 +1068,56 @@ function isPostgresLockCollisionError(error: unknown): boolean { || /server is already running/i.test(message); } +/* +FNXC:PostgresEmbedded 2026-07-23-10:40: +Issue #2411 (beta.4 follow-up): a cluster left in interrupted-recovery state +listens on its TCP port almost immediately but rejects every connection with +SQLSTATE 57P03 ("the database system is starting up") until crash recovery +finishes; a joiner racing the owner sees plain ECONNREFUSED instead. Both mean +"not yet accepting connections — wait", never "verify failed". Treating 57P03 +as fatal is what made beta.4 stop() its own just-launched postmaster ~0.2s into +recovery and then join the instance it had told to shut down. +*/ +export function isClusterStartingUpError(error: unknown): boolean { + const { code } = (error ?? {}) as { code?: string }; + // 57P03 cannot_connect_now covers "starting up", "in recovery mode", and + // "shutting down" — the cluster is alive but not yet queryable. + if (code === "57P03") return true; + const message = error instanceof Error ? error.message : String(error ?? ""); + return /the database system is (starting up|in recovery|shutting down)/i.test(message); +} + +/** + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Superset used only by the OWNED start's readiness wait: an owned postmaster + * that was just launched may also be in its pre-listen window, so socket-level + * connect failures are retryable there too. The JOIN path deliberately does NOT + * retry socket errors — a stale pid file from a crash resolves to a dead port, + * and the optimistic-join contract (resolve the URL, let the connection layer + * report it) must stay instant for that case. + */ +export function isClusterNotYetAcceptingError(error: unknown): boolean { + if (isClusterStartingUpError(error)) return true; + const { code } = (error ?? {}) as { code?: string }; + if (code === "ECONNREFUSED" || code === "ECONNRESET" || code === "ETIMEDOUT" || code === "CONNECT_TIMEOUT") { + return true; + } + const message = error instanceof Error ? error.message : String(error ?? ""); + return /ECONNREFUSED|ECONNRESET|CONNECT_TIMEOUT/i.test(message); +} + +/** Poll cadence while waiting for a starting/recovering cluster to accept connections. */ +const CLUSTER_ACCEPTING_POLL_MS = 500; +/** + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Bounded wait a JOINER gives a starting/recovering instance before falling + * back to the historical best-effort optimistic join. Recovery on the reported + * cluster completes in ~1s once the .pgrunner fsync stall is gone; 15s covers + * modest WAL replay without turning a stale-pid join into a long hang (the + * startup-factory retry layer bounds the rest). + */ +const JOINED_INSTANCE_RECOVERY_WAIT_MS = 15_000; + function isDuplicateDatabaseError(error: unknown): boolean { const { code, constraint_name: constraint } = (error ?? {}) as { code?: string; @@ -1549,6 +1599,18 @@ export class EmbeddedPostgresLifecycle { }); try { + /* + FNXC:PostgresEmbedded 2026-07-23-10:40: + Issue #2411 (beta.4 follow-up): an owned start on an interrupted data dir + must let crash recovery FINISH before any SQL runs. The elevated Windows + launcher declares readiness on a bare TCP accept, which succeeds while + recovery still rejects every connection with 57P03 — ensureDatabase then + failed, the outer catch called stop(), and Fusion fast-shutdown its own + postmaster 0.2s into recovery. Wait (bounded by the start timeout, which + also aborts this loop via `signal`) until the cluster genuinely accepts + connections; only then verify/create the application database. + */ + await this.waitForClusterAcceptingConnections(port, signal); await this.ensureDatabase(); } catch (error) { if (signal?.aborted) { @@ -1689,12 +1751,93 @@ export class EmbeddedPostgresLifecycle { * hard startup failure. */ private async ensureJoinedDatabase(port: number): Promise { - try { - await this.createDatabaseIfMissing(port); - } catch (error) { - this.options.onLog( - `embedded postgres: could not verify database "${this.options.database}" on joined instance at port ${port} (${error instanceof Error ? error.message : String(error)}); continuing — the connection layer will report an unreachable cluster`, - ); + /* + FNXC:PostgresEmbedded 2026-07-23-10:40: + Issue #2411 (beta.4 follow-up): a joined instance can be mid crash-recovery, + where PostgreSQL listens but rejects every connection with 57P03. A one-shot + verify turned that transient state into the "could not verify database on + joined instance" give-up path. Retry the RECOVERY signal (57P03 only) within + a bounded window; socket-level failures (dead stale-pid port) keep the + historical instant best-effort optimistic join (resolve the URL and let the + connection layer report the unreachable cluster). + */ + const deadline = Date.now() + JOINED_INSTANCE_RECOVERY_WAIT_MS; + let announced = false; + for (;;) { + try { + await this.createDatabaseIfMissing(port); + return; + } catch (error) { + if (isClusterStartingUpError(error) && Date.now() < deadline) { + if (!announced) { + announced = true; + this.options.onLog( + `embedded postgres: joined instance at port ${port} is not accepting connections yet (startup or crash recovery in progress); waiting before verifying database "${this.options.database}"`, + ); + } + await new Promise((resolve) => setTimeout(resolve, CLUSTER_ACCEPTING_POLL_MS)); + continue; + } + this.options.onLog( + `embedded postgres: could not verify database "${this.options.database}" on joined instance at port ${port} (${error instanceof Error ? error.message : String(error)}); continuing — the connection layer will report an unreachable cluster`, + ); + return; + } + } + } + + /** + * Block until the cluster at `port` accepts real connections (a `SELECT 1` on + * the maintenance database succeeds), retrying while it reports "starting + * up"/"in recovery" (57P03) or is not yet listening. + * + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Issue #2411: crash recovery on an interrupted cluster must be allowed to + * finish instead of being interpreted as a failed start (which shut the + * recovering postmaster down). Bounded by the caller's start timeout: the + * outer startBounded() race aborts `signal` when it fires, and a local + * deadline (the configured timeout, or the default when timeouts are + * disabled) backstops callers without a signal. + */ + private async waitForClusterAcceptingConnections( + port: number, + signal?: AbortSignal, + ): Promise { + // FNXC:PostgresEmbedded 2026-07-23-10:40: mirrors the elevated-path skip — + // a test-injected mock ctor has no real server to poll, so the wait would + // spin against a dead port until the start timeout in every mocked test. + if (embeddedPostgresCtorIsTestOverride) return; + const budgetMs = + this.options.startTimeoutMs > 0 && Number.isFinite(this.options.startTimeoutMs) + ? this.options.startTimeoutMs + : DEFAULT_START_TIMEOUT_MS; + const deadline = Date.now() + budgetMs; + let announced = false; + for (;;) { + if (signal?.aborted) throw new EmbeddedStartCancelledError(this.options.dataDir); + const sql = this.openMaintenanceSqlOn(port); + let lastError: unknown; + try { + await sql`SELECT 1 AS one`; + return; + } catch (error) { + lastError = error; + } finally { + await sql.end({ timeout: 5 }).catch(() => {}); + } + if (!isClusterNotYetAcceptingError(lastError)) throw lastError; + if (Date.now() >= deadline) { + throw new Error( + `embedded postgres: cluster on port ${port} did not accept connections within ${budgetMs}ms (crash recovery may still be running); last error: ${lastError instanceof Error ? lastError.message : String(lastError)}`, + ); + } + if (!announced) { + announced = true; + this.options.onLog( + `embedded postgres: cluster on port ${port} is still starting up (crash recovery may be in progress); waiting for it to accept connections`, + ); + } + await new Promise((resolve) => setTimeout(resolve, CLUSTER_ACCEPTING_POLL_MS)); } } diff --git a/packages/core/src/postgres/embedded-windows-elevated.ts b/packages/core/src/postgres/embedded-windows-elevated.ts index 5fe0e0d317..4e024ac673 100644 --- a/packages/core/src/postgres/embedded-windows-elevated.ts +++ b/packages/core/src/postgres/embedded-windows-elevated.ts @@ -22,7 +22,7 @@ import { spawn, spawnSync } from "node:child_process"; import { existsSync, mkdirSync, readdirSync, readFileSync, rmSync } from "node:fs"; import { createConnection } from "node:net"; -import { join } from "node:path"; +import { basename, dirname, join } from "node:path"; /** Handle returned by {@link startServerElevatedRestricted}; call stop() to kill it. */ export interface ElevatedServerHandle { @@ -234,6 +234,24 @@ function readTail(file: string, max: number): string { } } +/* +FNXC:PostgresEmbedded 2026-07-23-10:40: +Issue #2411 (beta.4 follow-up): the pgctl runner log used to live INSIDE the +data directory (/.pgrunner). On an interrupted cluster, Windows crash +recovery runs SyncDataDirectory(), which fsync-walks every file under the data +dir — including Fusion's own live pgctl log, whose write handle the postmaster +inherits from pg_ctl as its stderr. PostgreSQL's fsync open then fails with +"could not open file ./.pgrunner/pgctl-.log: sharing violation … retrying +for 30 seconds", adding a 30s stall to every crash recovery (reporter measured +~1s recovery once the log was elsewhere). The runner dir is therefore a SIBLING +of the data dir (.pgrunner-), so recovery's data-dir walk can never +touch it. The legacy in-dataDir .pgrunner directory is swept best-effort. +*/ +export function resolvePgRunnerDir(dataDir: string): string { + const normalized = dataDir.replace(/[\\/]+$/, ""); + return join(dirname(normalized), `.pgrunner-${basename(normalized)}`); +} + /** * FNXC:WindowsDesktopPackaging 2026-07-17-22:30: * Per-launch log file names + best-effort pruning replace the old truncate-on @@ -243,8 +261,18 @@ function readTail(file: string, max: number): string { * Legacy wrapper artifacts (launch.bat/launch.ps1/wrapper.log/postgres.log) * are swept the same way. */ -function prepareRunDir(runDir: string): string { +function prepareRunDir(runDir: string, legacyInDataDirRunDir?: string): string { mkdirSync(runDir, { recursive: true }); + // FNXC:PostgresEmbedded 2026-07-23-10:40: sweep the pre-#2411-fix runner dir + // that lived inside the data dir; leaving it would keep the crash-recovery + // fsync sharing-violation stall alive for upgraded installs. + if (legacyInDataDirRunDir) { + try { + rmSync(legacyInDataDirRunDir, { recursive: true, force: true }); + } catch { + // A file held open by a live process stays; it is swept on a later boot. + } + } const legacy = ["launch.bat", "launch.ps1", "wrapper.log", "postgres.log"]; let entries: string[] = []; try { @@ -264,6 +292,26 @@ function prepareRunDir(runDir: string): string { return join(runDir, `pgctl-${Date.now()}.log`); } +/* +FNXC:PostgresEmbedded 2026-07-23-10:40: +Issue #2411 (beta.4 follow-up): an interrupted cluster runs crash recovery +before accepting queries, and any client that connects during that window is +rejected with `FATAL: the database system is starting up` (SQLSTATE 57P03). +Those lines are normal recovery progress, not a startup failure — treating them +as fatal is what issued a fast-shutdown request ~0.2s into recovery and wedged +the boot. Strip them (and their in-recovery sibling) before scanning the log +tail for genuine startup errors. +*/ +export function containsElevatedStartupFatal(tail: string): boolean { + const scan = tail + .split("\n") + .filter((line) => !/the database system is (starting up|in recovery)/i.test(line)) + .join("\n"); + return /\bFATAL\b|\bPANIC\b|could not (bind|start|create|access|connect|load)|not permitted|Permission denied|is not the owner/i.test( + scan, + ); +} + /** * Start postgres.exe on an elevated Windows process via pg_ctl's restricted * token re-exec, and resolve once it is accepting connections. Rejects with a @@ -280,8 +328,8 @@ export async function startServerElevatedRestricted( if (!existsSync(pgCtl)) { throw new Error(`embedded postgres: pg_ctl.exe not found at ${pgCtl}`); } - const runDir = join(opts.dataDir, ".pgrunner"); - const logFile = prepareRunDir(runDir); + const runDir = resolvePgRunnerDir(opts.dataDir); + const logFile = prepareRunDir(runDir, join(opts.dataDir, ".pgrunner")); const safeFlags = sanitizePostgresFlags(opts.postgresFlags); const args = buildPgCtlStartArgs( opts.dataDir, @@ -414,7 +462,7 @@ export async function startServerElevatedRestricted( lastSnapshot = tail; opts.onLog(`elevated diagnostic pg={${tail.slice(-400)}}`); } - if (/\bFATAL\b|\bPANIC\b|could not (bind|start|create|access|connect|load)|not permitted|Permission denied|is not the owner/i.test(tail)) { + if (containsElevatedStartupFatal(tail)) { killAll(); throw new Error( `embedded postgres: elevated postgres reported a startup error before opening the port.\n${tail}`, diff --git a/packages/core/src/postgres/startup-factory.ts b/packages/core/src/postgres/startup-factory.ts index b0323e286c..1a593a6726 100644 --- a/packages/core/src/postgres/startup-factory.ts +++ b/packages/core/src/postgres/startup-factory.ts @@ -305,11 +305,34 @@ class JoinedInstanceUnreachableError extends Error { } } -/** Matches a TCP-level connection-refused failure (ECONNREFUSED / "connect ECONNREFUSED"). */ +/** + * Matches a joined instance that is not (yet) queryable: TCP-level + * connection-refused, or PostgreSQL's 57P03 "cannot connect now" rejection. + * + * FNXC:PostgresEmbedded 2026-07-23-10:40: + * Issue #2411 (beta.4 follow-up): a joined instance running crash recovery on + * an interrupted cluster LISTENS but rejects every connection with FATAL "the + * database system is starting up" (57P03) until redo completes. That is the + * same "not yet accepting connections" startup race as the ECONNREFUSED bind + * window and must be retried, not surfaced as a hard schema-backend failure. + */ function isConnectionRefusedError(chainText: string): boolean { - return /ECONNREFUSED/i.test(chainText); + return ( + /ECONNREFUSED/i.test(chainText) || + /the database system is (starting up|in recovery|shutting down)/i.test(chainText) + ); } +/* +FNXC:PostgresEmbedded 2026-07-23-10:40: +Issue #2411 (beta.4 follow-up): one 500ms retry was not enough to outlast crash +recovery on an interrupted cluster — the boot gave up while redo was still +running and parked the dashboard in a manual-restart dead shell. Back off across +a bounded window (~15s of delay) so a recovering joined instance is given time +to finish; a genuinely dead target still fails, just slightly later. +*/ +const JOINED_INSTANCE_RETRY_DELAYS_MS: readonly number[] = [500, 2_000, 4_000, 8_000]; + /** Matches PostgreSQL's encoding-conversion failure raised by a non-UTF-8 cluster. */ export function isEncodingConversionError(chainText: string): boolean { return /has no equivalent in encoding/i.test(chainText); @@ -354,26 +377,35 @@ async function bootSchemaBackend( options: Pick, bypassProjectIsolation = false, ): Promise { - try { - return await bootSchemaBackendOnce(options, bypassProjectIsolation); - } catch (error) { - if (error instanceof JoinedInstanceUnreachableError) { + let joinedRetryAttempt = 0; + for (;;) { + try { + return await bootSchemaBackendOnce(options, bypassProjectIsolation); + } catch (error) { + if ( + error instanceof JoinedInstanceUnreachableError && + joinedRetryAttempt < JOINED_INSTANCE_RETRY_DELAYS_MS.length + ) { + const delayMs = JOINED_INSTANCE_RETRY_DELAYS_MS[joinedRetryAttempt]; + joinedRetryAttempt += 1; + log.warn( + "startup-factory: joined embedded postgres instance was not yet accepting connections " + + "(startup race with the true owner's TCP bind, or crash recovery still running — " + + "see FNXC:PostgresStartupRace 2026-07-20-22:10 and FNXC:PostgresEmbedded 2026-07-23-10:40). " + + `Retrying in ${delayMs}ms (attempt ${joinedRetryAttempt}/${JOINED_INSTANCE_RETRY_DELAYS_MS.length}).`, + ); + await new Promise((resolve) => setTimeout(resolve, delayMs)); + continue; + } + if (!(error instanceof NonUtf8EmbeddedClusterError)) throw error; log.warn( - "startup-factory: joined embedded postgres instance was not yet accepting connections " + - "(startup race with the true owner's TCP bind — see FNXC:PostgresStartupRace 2026-07-20-22:10). " + - "Retrying once after a short delay.", + `startup-factory: embedded cluster at ${error.dataDir} was created with a non-UTF-8 OS-locale ` + + `encoding by an earlier version and never completed a boot (issue #2286). ` + + `Re-initializing it as UTF-8 and retrying once.`, ); - await new Promise((resolve) => setTimeout(resolve, 500)); + rmSync(error.dataDir, { recursive: true, force: true, maxRetries: 5, retryDelay: 200 }); return await bootSchemaBackendOnce(options, bypassProjectIsolation); } - if (!(error instanceof NonUtf8EmbeddedClusterError)) throw error; - log.warn( - `startup-factory: embedded cluster at ${error.dataDir} was created with a non-UTF-8 OS-locale ` + - `encoding by an earlier version and never completed a boot (issue #2286). ` + - `Re-initializing it as UTF-8 and retrying once.`, - ); - rmSync(error.dataDir, { recursive: true, force: true, maxRetries: 5, retryDelay: 200 }); - return await bootSchemaBackendOnce(options, bypassProjectIsolation); } }