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
7
.changeset/embedded-pg-crash-recovery-2411.md
Normal file
7
.changeset/embedded-pg-crash-recovery-2411.md
Normal 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.
|
||||
@@ -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<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)", () => {
|
||||
it("EmbeddedStartTimeoutError carries the timeout and data dir", () => {
|
||||
const err = new EmbeddedStartTimeoutError(5000, "/tmp/data");
|
||||
|
||||
@@ -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-<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", () => {
|
||||
it("carries the port and sanitized flags in the -o option string", () => {
|
||||
expect(buildPgCtlOptionsString(55499, ["-c", "shared_memory_type=sysv"])).toBe(
|
||||
|
||||
@@ -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<void> {
|
||||
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<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));
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -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 (<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:
|
||||
* 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}`,
|
||||
|
||||
@@ -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<CreateTaskStoreForBackendOptions, "env" | "backend" | "embeddedPgRequested" | "embeddedDataDir" | "poolMax" | "globalSettingsDir">,
|
||||
bypassProjectIsolation = false,
|
||||
): Promise<SchemaBackendBootResult> {
|
||||
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);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user