fix(#2411): let embedded PostgreSQL crash recovery finish instead of racing it

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-<dataDirName> 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 <noreply@anthropic.com>
This commit is contained in:
gsxdsm
2026-07-23 09:13:21 -07:00
parent d2e41e490f
commit dc132071d5
6 changed files with 458 additions and 29 deletions

View File

@@ -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-<dataDirName>` 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.

View File

@@ -38,6 +38,8 @@ import {
resolveEmbeddedMaxConnections, resolveEmbeddedMaxConnections,
DEFAULT_EMBEDDED_MAX_CONNECTIONS, DEFAULT_EMBEDDED_MAX_CONNECTIONS,
DEFAULT_EMBEDDED_MAX_CONNECTIONS_WIN32, DEFAULT_EMBEDDED_MAX_CONNECTIONS_WIN32,
isClusterNotYetAcceptingError,
isClusterStartingUpError,
isDataDirInitialized, isDataDirInitialized,
isWindowsElevatedAdmin, isWindowsElevatedAdmin,
normalizeMacosEmbeddedPostgresDylibSymlinks, 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<void>;
};
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<void> };
(sql as { end: (opts?: unknown) => Promise<void> }).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<void>;
};
internal.openMaintenanceSqlOn = () => {
const sql = (() =>
Promise.reject(new Error('password authentication failed for user "postgres"'))) as unknown as {
end: (opts?: unknown) => Promise<void>;
};
(sql as { end: (opts?: unknown) => Promise<void> }).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<void>;
},
"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)", () => { describe("embedded-lifecycle: startup timeout (P1 #24)", () => {
it("EmbeddedStartTimeoutError carries the timeout and data dir", () => { it("EmbeddedStartTimeoutError carries the timeout and data dir", () => {
const err = new EmbeddedStartTimeoutError(5000, "/tmp/data"); const err = new EmbeddedStartTimeoutError(5000, "/tmp/data");

View File

@@ -1,8 +1,11 @@
import { describe, expect, it } from "vitest"; import { describe, expect, it } from "vitest";
import { join, sep } from "node:path";
import { DEFAULT_EMBEDDED_POSTGRES_FLAGS } from "../../postgres/embedded-lifecycle.js"; import { DEFAULT_EMBEDDED_POSTGRES_FLAGS } from "../../postgres/embedded-lifecycle.js";
import { import {
buildPgCtlOptionsString, buildPgCtlOptionsString,
buildPgCtlStartArgs, buildPgCtlStartArgs,
containsElevatedStartupFatal,
resolvePgRunnerDir,
sanitizePostgresFlags, sanitizePostgresFlags,
withWindowsNativeBinPath, withWindowsNativeBinPath,
WindowsPostgresFatalDetector, 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-<ts>.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", () => { describe("pg_ctl elevated launch composition", () => {
it("carries the port and sanitized flags in the -o option string", () => { it("carries the port and sanitized flags in the -o option string", () => {
expect(buildPgCtlOptionsString(55499, ["-c", "shared_memory_type=sysv"])).toBe( expect(buildPgCtlOptionsString(55499, ["-c", "shared_memory_type=sysv"])).toBe(

View File

@@ -1068,6 +1068,56 @@ function isPostgresLockCollisionError(error: unknown): boolean {
|| /server is already running/i.test(message); || /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 { function isDuplicateDatabaseError(error: unknown): boolean {
const { code, constraint_name: constraint } = (error ?? {}) as { const { code, constraint_name: constraint } = (error ?? {}) as {
code?: string; code?: string;
@@ -1549,6 +1599,18 @@ export class EmbeddedPostgresLifecycle {
}); });
try { 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(); await this.ensureDatabase();
} catch (error) { } catch (error) {
if (signal?.aborted) { if (signal?.aborted) {
@@ -1689,12 +1751,93 @@ export class EmbeddedPostgresLifecycle {
* hard startup failure. * hard startup failure.
*/ */
private async ensureJoinedDatabase(port: number): Promise<void> { private async ensureJoinedDatabase(port: number): Promise<void> {
try { /*
await this.createDatabaseIfMissing(port); FNXC:PostgresEmbedded 2026-07-23-10:40:
} catch (error) { Issue #2411 (beta.4 follow-up): a joined instance can be mid crash-recovery,
this.options.onLog( where PostgreSQL listens but rejects every connection with 57P03. A one-shot
`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`, 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<void>((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<void> {
// 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<void>((resolve) => setTimeout(resolve, CLUSTER_ACCEPTING_POLL_MS));
} }
} }

View File

@@ -22,7 +22,7 @@
import { spawn, spawnSync } from "node:child_process"; import { spawn, spawnSync } from "node:child_process";
import { existsSync, mkdirSync, readdirSync, readFileSync, rmSync } from "node:fs"; import { existsSync, mkdirSync, readdirSync, readFileSync, rmSync } from "node:fs";
import { createConnection } from "node:net"; 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. */ /** Handle returned by {@link startServerElevatedRestricted}; call stop() to kill it. */
export interface ElevatedServerHandle { 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 (<dataDir>/.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-<ts>.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-<dataDirName>), 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: * FNXC:WindowsDesktopPackaging 2026-07-17-22:30:
* Per-launch log file names + best-effort pruning replace the old truncate-on * 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) * Legacy wrapper artifacts (launch.bat/launch.ps1/wrapper.log/postgres.log)
* are swept the same way. * are swept the same way.
*/ */
function prepareRunDir(runDir: string): string { function prepareRunDir(runDir: string, legacyInDataDirRunDir?: string): string {
mkdirSync(runDir, { recursive: true }); 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"]; const legacy = ["launch.bat", "launch.ps1", "wrapper.log", "postgres.log"];
let entries: string[] = []; let entries: string[] = [];
try { try {
@@ -264,6 +292,26 @@ function prepareRunDir(runDir: string): string {
return join(runDir, `pgctl-${Date.now()}.log`); 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 * 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 * token re-exec, and resolve once it is accepting connections. Rejects with a
@@ -280,8 +328,8 @@ export async function startServerElevatedRestricted(
if (!existsSync(pgCtl)) { if (!existsSync(pgCtl)) {
throw new Error(`embedded postgres: pg_ctl.exe not found at ${pgCtl}`); throw new Error(`embedded postgres: pg_ctl.exe not found at ${pgCtl}`);
} }
const runDir = join(opts.dataDir, ".pgrunner"); const runDir = resolvePgRunnerDir(opts.dataDir);
const logFile = prepareRunDir(runDir); const logFile = prepareRunDir(runDir, join(opts.dataDir, ".pgrunner"));
const safeFlags = sanitizePostgresFlags(opts.postgresFlags); const safeFlags = sanitizePostgresFlags(opts.postgresFlags);
const args = buildPgCtlStartArgs( const args = buildPgCtlStartArgs(
opts.dataDir, opts.dataDir,
@@ -414,7 +462,7 @@ export async function startServerElevatedRestricted(
lastSnapshot = tail; lastSnapshot = tail;
opts.onLog(`elevated diagnostic pg={${tail.slice(-400)}}`); 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(); killAll();
throw new Error( throw new Error(
`embedded postgres: elevated postgres reported a startup error before opening the port.\n${tail}`, `embedded postgres: elevated postgres reported a startup error before opening the port.\n${tail}`,

View File

@@ -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 { 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. */ /** Matches PostgreSQL's encoding-conversion failure raised by a non-UTF-8 cluster. */
export function isEncodingConversionError(chainText: string): boolean { export function isEncodingConversionError(chainText: string): boolean {
return /has no equivalent in encoding/i.test(chainText); return /has no equivalent in encoding/i.test(chainText);
@@ -354,26 +377,35 @@ async function bootSchemaBackend(
options: Pick<CreateTaskStoreForBackendOptions, "env" | "backend" | "embeddedPgRequested" | "embeddedDataDir" | "poolMax" | "globalSettingsDir">, options: Pick<CreateTaskStoreForBackendOptions, "env" | "backend" | "embeddedPgRequested" | "embeddedDataDir" | "poolMax" | "globalSettingsDir">,
bypassProjectIsolation = false, bypassProjectIsolation = false,
): Promise<SchemaBackendBootResult> { ): Promise<SchemaBackendBootResult> {
try { let joinedRetryAttempt = 0;
return await bootSchemaBackendOnce(options, bypassProjectIsolation); for (;;) {
} catch (error) { try {
if (error instanceof JoinedInstanceUnreachableError) { 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( log.warn(
"startup-factory: joined embedded postgres instance was not yet accepting connections " + `startup-factory: embedded cluster at ${error.dataDir} was created with a non-UTF-8 OS-locale ` +
"(startup race with the true owner's TCP bind — see FNXC:PostgresStartupRace 2026-07-20-22:10). " + `encoding by an earlier version and never completed a boot (issue #2286). ` +
"Retrying once after a short delay.", `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); 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);
} }
} }