mirror of
https://github.com/Routstr/routstrd.git
synced 2026-09-14 02:55:07 +00:00
fix(cli): wait for old daemon to finish ongoing requests before restarting (wallet-lock race) (#98)
* fix(cli): wait for the old daemon to finish ongoing requests during restart The daemon shuts down gracefully: it stops listening right after /stop, but keeps serving ongoing requests before disposing of the wallet and releasing wallet.pid. The restart flows only waited for the health check to go down, then spawned a replacement daemon that failed to claim the routstrd wallet lock and exited with code 1, surfacing a confusing 'Cannot claim the routstrd wallet lock ... PID X is still running' error. Add waitForDaemonToExit() and use it in restart, mode, the post-update restart, and stop: - Phase 1: wait (10s) for the health check to stop responding. - Phase 2: while the old process still holds the wallet lock, show 'Finishing all ongoing requests...' (heartbeat every 10s) and wait up to 10 minutes for it to exit. A stale lock (dead PID) is not waited on; after the timeout the error names the holding PID and how to force it. stop now also waits for full exit instead of returning as soon as /stop is acknowledged, and no longer auto-starts a daemon when none is running. * fix(cli): offer 'kill -9 <PID>' to force stop a draining daemon The drain progress messages and the drain-timeout error now suggest 'kill -9 <PID>' so the user can force the old daemon out instead of waiting for stuck requests. A plain SIGTERM would not work: the daemon's signal handler re-runs the same graceful shutdown (server.close()), which keeps waiting for ongoing requests, so only SIGKILL can interrupt a stuck drain. The wait loop already treats the resulting dead-PID lock as released (same liveness semantics as claimPidFile), so the restart proceeds cleanly. The heartbeat interval is now injectable (drainHeartbeatMs, default 10s) like the other timing knobs, which also lets the tests cover the heartbeat message. --------- Co-authored-by: redshift <213178690+1ftredsh@users.noreply.github.com>
This commit is contained in:
+32
-35
@@ -11,6 +11,7 @@ import {
|
||||
getDaemonBaseUrl,
|
||||
getUserNpub,
|
||||
} from "./utils/daemon-client";
|
||||
import { waitForDaemonToExit } from "./utils/daemon-stop";
|
||||
import {
|
||||
listClientsAction,
|
||||
deleteClientAction,
|
||||
@@ -195,18 +196,10 @@ async function restartDaemonsAfterUpdate(): Promise<void> {
|
||||
|
||||
await callDaemon("/stop", { method: "POST" });
|
||||
|
||||
// Wait for HTTP health check to fail AND wallet lock to be released.
|
||||
const pidFilePath = walletPidPath();
|
||||
for (let i = 0; i < 100; i++) {
|
||||
await new Promise((resolve) => setTimeout(resolve, 100));
|
||||
const healthDown = !(await isDaemonRunning());
|
||||
const pidFileReleased = !existsSync(pidFilePath);
|
||||
if (healthDown && pidFileReleased) break;
|
||||
}
|
||||
|
||||
if (await isDaemonRunning()) {
|
||||
throw new Error("routstrd did not stop within 10 seconds");
|
||||
}
|
||||
// Wait for the old daemon to fully exit: it keeps serving ongoing
|
||||
// requests before it releases the wallet lock and the new daemon can
|
||||
// safely claim it.
|
||||
await waitForDaemonToExit({ pidFilePath: walletPidPath() });
|
||||
console.log("routstrd daemon stopped.");
|
||||
|
||||
await stopLegacyCocod();
|
||||
@@ -2197,7 +2190,21 @@ program
|
||||
.command("stop")
|
||||
.description("Stop the background daemon")
|
||||
.action(async () => {
|
||||
await handleDaemonCommand("/stop", { method: "POST" });
|
||||
if (!(await isDaemonRunning())) {
|
||||
console.log("Daemon was not running.");
|
||||
return;
|
||||
}
|
||||
await callDaemon("/stop", { method: "POST" });
|
||||
|
||||
// The daemon exits only after ongoing requests finish; wait for it so
|
||||
// the wallet lock is actually free when this command returns.
|
||||
try {
|
||||
await waitForDaemonToExit({ pidFilePath: walletPidPath() });
|
||||
} catch (error) {
|
||||
logger.error(error instanceof Error ? error.message : String(error));
|
||||
process.exit(1);
|
||||
}
|
||||
console.log("Daemon stopped.");
|
||||
});
|
||||
|
||||
// Service - PM2 management
|
||||
@@ -2310,19 +2317,12 @@ program
|
||||
console.log("Stopping daemon...");
|
||||
await callDaemon("/stop", { method: "POST" });
|
||||
|
||||
// Wait for HTTP health check to fail AND wallet lock to be released.
|
||||
const pidFilePath = walletPidPath();
|
||||
for (let i = 0; i < 100; i++) {
|
||||
await new Promise((resolve) => setTimeout(resolve, 100));
|
||||
const healthDown = !(await isDaemonRunning());
|
||||
const pidFileReleased = !existsSync(pidFilePath);
|
||||
if (healthDown && pidFileReleased) {
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
if (await isDaemonRunning()) {
|
||||
logger.error("Daemon failed to stop within 10 seconds");
|
||||
// Wait for the old daemon to fully exit so the wallet lock is free
|
||||
// before a new daemon is spawned.
|
||||
try {
|
||||
await waitForDaemonToExit({ pidFilePath: walletPidPath() });
|
||||
} catch (error) {
|
||||
logger.error(error instanceof Error ? error.message : String(error));
|
||||
process.exit(1);
|
||||
}
|
||||
console.log("Daemon stopped.");
|
||||
@@ -2401,15 +2401,12 @@ program
|
||||
console.log("Stopping daemon...");
|
||||
await callDaemon("/stop", { method: "POST" });
|
||||
|
||||
for (let i = 0; i < 50; i++) {
|
||||
await new Promise((resolve) => setTimeout(resolve, 100));
|
||||
if (!(await isDaemonRunning())) {
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
if (await isDaemonRunning()) {
|
||||
logger.error("Daemon failed to stop within 5 seconds");
|
||||
// Wait for the old daemon to fully exit so the wallet lock is free
|
||||
// before a new daemon is spawned.
|
||||
try {
|
||||
await waitForDaemonToExit({ pidFilePath: walletPidPath() });
|
||||
} catch (error) {
|
||||
logger.error(error instanceof Error ? error.message : String(error));
|
||||
process.exit(1);
|
||||
}
|
||||
console.log("Daemon stopped.");
|
||||
|
||||
@@ -260,7 +260,8 @@ export function isZombieProcess(
|
||||
}
|
||||
}
|
||||
|
||||
function defaultIsProcessRunning(pid: number): boolean {
|
||||
/** Test whether a PID is alive; dead-but-unreaped zombies count as dead. */
|
||||
export function defaultIsProcessRunning(pid: number): boolean {
|
||||
try {
|
||||
process.kill(pid, 0);
|
||||
} catch (error) {
|
||||
|
||||
+2
-1
@@ -88,7 +88,8 @@ function printStartupProgress(offset: number): {
|
||||
}
|
||||
}
|
||||
|
||||
function formatElapsed(elapsedMs: number): string {
|
||||
/** Format an elapsed duration as "45s" or "2m 5s". */
|
||||
export function formatElapsed(elapsedMs: number): string {
|
||||
const seconds = Math.floor(elapsedMs / 1000);
|
||||
if (seconds < 60) return `${seconds}s`;
|
||||
return `${Math.floor(seconds / 60)}m ${seconds % 60}s`;
|
||||
|
||||
@@ -0,0 +1,125 @@
|
||||
import { existsSync, readFileSync } from "fs";
|
||||
import { isDaemonRunning } from "./daemon-client";
|
||||
import { defaultIsProcessRunning } from "../daemon/wallet/coco-client";
|
||||
import { walletPidPath } from "../daemon/wallet/paths";
|
||||
import { formatElapsed } from "../start-daemon";
|
||||
|
||||
/**
|
||||
* Wait for a daemon that was asked to stop (POST /stop) to fully exit.
|
||||
*
|
||||
* The daemon shuts down gracefully: it stops accepting new connections
|
||||
* right away, but keeps serving ongoing requests until they finish; only
|
||||
* then does it dispose of the wallet, release the wallet PID lock, and
|
||||
* exit. Spawning a replacement before the lock is released makes it abort
|
||||
* with "Cannot claim the routstrd wallet lock", so restarts must wait for
|
||||
* the old process to fully exit — telling the user why it is taking a
|
||||
* while ("Finishing all ongoing requests...") and how to force it
|
||||
* ("run 'kill -9 <PID>' to force stop") instead of racing ahead.
|
||||
*/
|
||||
export interface WaitForDaemonToExitOptions {
|
||||
/** Wallet PID lock file held by the running daemon. */
|
||||
pidFilePath?: string;
|
||||
/** Returns true while the daemon still answers /health. */
|
||||
isHealthy?: () => Promise<boolean>;
|
||||
/** Returns the live PID recorded in the wallet lock file, or null when the
|
||||
* file is gone or unreadable. */
|
||||
readLockPid?: (pidFilePath: string) => number | null;
|
||||
/** Returns true when a PID is alive (zombies count as dead). */
|
||||
isProcessRunning?: (pid: number) => boolean;
|
||||
sleep?: (ms: number) => Promise<void>;
|
||||
log?: (message: string) => void;
|
||||
/** How long to wait for the health check to stop responding after /stop. */
|
||||
healthTimeoutMs?: number;
|
||||
/** Silent window before reporting that ongoing requests are finishing. */
|
||||
drainGraceMs?: number;
|
||||
/** How long to wait for the old daemon to exit and release the lock. */
|
||||
drainTimeoutMs?: number;
|
||||
/** How often to re-report that ongoing requests are still finishing. */
|
||||
drainHeartbeatMs?: number;
|
||||
/** Interval between health and lock polls. */
|
||||
pollIntervalMs?: number;
|
||||
}
|
||||
|
||||
/** How often to re-report that the daemon is still finishing requests. */
|
||||
const DRAIN_HEARTBEAT_MS = 10_000;
|
||||
|
||||
function defaultReadLockPid(pidFilePath: string): number | null {
|
||||
if (!existsSync(pidFilePath)) return null;
|
||||
try {
|
||||
const pid = Number.parseInt(readFileSync(pidFilePath, "utf8").trim(), 10);
|
||||
return Number.isInteger(pid) && pid > 0 ? pid : null;
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
export async function waitForDaemonToExit(
|
||||
options: WaitForDaemonToExitOptions = {},
|
||||
): Promise<void> {
|
||||
const {
|
||||
pidFilePath = walletPidPath(),
|
||||
isHealthy = isDaemonRunning,
|
||||
readLockPid = defaultReadLockPid,
|
||||
isProcessRunning = defaultIsProcessRunning,
|
||||
sleep = (ms: number) =>
|
||||
new Promise<void>((resolve) => setTimeout(resolve, ms)),
|
||||
log = (message: string) => console.log(message),
|
||||
healthTimeoutMs = 10_000,
|
||||
drainGraceMs = 1_000,
|
||||
drainTimeoutMs = 10 * 60_000,
|
||||
drainHeartbeatMs = DRAIN_HEARTBEAT_MS,
|
||||
pollIntervalMs = 100,
|
||||
} = options;
|
||||
|
||||
// Phase 1: the daemon stops accepting new connections promptly after
|
||||
// /stop, so its health check should stop responding within seconds.
|
||||
const healthDeadline = Date.now() + healthTimeoutMs;
|
||||
while (await isHealthy()) {
|
||||
if (Date.now() >= healthDeadline) {
|
||||
throw new Error(
|
||||
`routstrd did not stop within ${Math.round(healthTimeoutMs / 1000)} seconds`,
|
||||
);
|
||||
}
|
||||
await sleep(pollIntervalMs);
|
||||
}
|
||||
|
||||
// Phase 2: the process stays alive while it finishes ongoing requests and
|
||||
// disposes of the wallet. The wallet PID lock is released only right before
|
||||
// the process exits, so wait for it (or for the recorded PID to die). Both
|
||||
// progress messages offer 'kill -9 <PID>': only SIGKILL interrupts a stuck
|
||||
// drain — a plain SIGTERM just re-runs the same graceful shutdown.
|
||||
const drainStartedAt = Date.now();
|
||||
const drainDeadline = drainStartedAt + drainTimeoutMs;
|
||||
let drainAnnounced = false;
|
||||
let nextHeartbeatAt = 0;
|
||||
|
||||
for (;;) {
|
||||
const lockPid = readLockPid(pidFilePath);
|
||||
if (lockPid === null || !isProcessRunning(lockPid)) return;
|
||||
|
||||
const now = Date.now();
|
||||
if (now >= drainDeadline) {
|
||||
throw new Error(
|
||||
`the previous daemon (PID ${lockPid}) did not finish its ongoing requests within ` +
|
||||
`${formatElapsed(drainTimeoutMs)} and still holds the wallet lock at ${pidFilePath}. ` +
|
||||
`Wait for it to exit and try again, or run 'kill -9 ${lockPid}' to force it.`,
|
||||
);
|
||||
}
|
||||
|
||||
if (!drainAnnounced && now - drainStartedAt >= drainGraceMs) {
|
||||
drainAnnounced = true;
|
||||
log(
|
||||
` Finishing all ongoing requests... (run 'kill -9 ${lockPid}' to force stop)`,
|
||||
);
|
||||
nextHeartbeatAt = now + drainHeartbeatMs;
|
||||
} else if (drainAnnounced && now >= nextHeartbeatAt) {
|
||||
log(
|
||||
` Still finishing ongoing requests (${formatElapsed(now - drainStartedAt)} elapsed)... ` +
|
||||
`(run 'kill -9 ${lockPid}' to force stop)`,
|
||||
);
|
||||
nextHeartbeatAt += drainHeartbeatMs;
|
||||
}
|
||||
|
||||
await sleep(pollIntervalMs);
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,171 @@
|
||||
import { afterEach, describe, expect, test } from "bun:test";
|
||||
import { mkdtempSync, rmSync, writeFileSync } from "fs";
|
||||
import { tmpdir } from "os";
|
||||
import { join } from "path";
|
||||
import { waitForDaemonToExit, type WaitForDaemonToExitOptions } from "../../src/utils/daemon-stop";
|
||||
|
||||
const PID_FILE = "/tmp/routstrd-test/wallet.pid";
|
||||
const tempDirs: string[] = [];
|
||||
|
||||
function makeTempDir(): string {
|
||||
const dir = mkdtempSync(join(tmpdir(), "routstrd-daemon-stop-test-"));
|
||||
tempDirs.push(dir);
|
||||
return dir;
|
||||
}
|
||||
|
||||
afterEach(() => {
|
||||
for (const dir of tempDirs.splice(0)) {
|
||||
rmSync(dir, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
/** Consume scripted values from the front; repeat the fallback afterwards. */
|
||||
function scripted<T>(values: T[], fallback: T): () => T {
|
||||
return () => (values.length > 0 ? values.shift()! : fallback);
|
||||
}
|
||||
|
||||
function runWith(
|
||||
overrides: {
|
||||
health?: boolean[];
|
||||
lockPids?: Array<number | null>;
|
||||
runningPids?: number[];
|
||||
} = {},
|
||||
options: WaitForDaemonToExitOptions = {},
|
||||
) {
|
||||
const logs: string[] = [];
|
||||
const runningPids = new Set(overrides.runningPids ?? []);
|
||||
const nextHealth = scripted(overrides.health ?? [], false);
|
||||
const nextLockPid = scripted(overrides.lockPids ?? [], null);
|
||||
const promise = waitForDaemonToExit({
|
||||
pidFilePath: PID_FILE,
|
||||
isHealthy: () => Promise.resolve(nextHealth()),
|
||||
readLockPid: () => nextLockPid(),
|
||||
isProcessRunning: (pid: number) => runningPids.has(pid),
|
||||
sleep: () => Promise.resolve(),
|
||||
log: (message: string) => logs.push(message),
|
||||
pollIntervalMs: 1,
|
||||
// Keep the grace window tiny so draining is reported on the first poll.
|
||||
drainGraceMs: 0,
|
||||
...options,
|
||||
});
|
||||
return { logs, promise };
|
||||
}
|
||||
|
||||
describe("waitForDaemonToExit", () => {
|
||||
test("resolves once the health check is down and the lock is released", async () => {
|
||||
const { logs, promise } = runWith({
|
||||
health: [true, true],
|
||||
lockPids: [null],
|
||||
});
|
||||
await promise;
|
||||
expect(logs).toEqual([]);
|
||||
});
|
||||
|
||||
test("waits for the old daemon to finish ongoing requests", async () => {
|
||||
const { logs, promise } = runWith({
|
||||
health: [],
|
||||
// The old daemon holds the lock for a few polls, then releases it.
|
||||
lockPids: [5923, 5923, 5923, null],
|
||||
runningPids: [5923],
|
||||
});
|
||||
await promise;
|
||||
expect(logs).toEqual([
|
||||
" Finishing all ongoing requests... (run 'kill -9 5923' to force stop)",
|
||||
]);
|
||||
});
|
||||
|
||||
test("re-reports how to force stop while ongoing requests are still finishing", async () => {
|
||||
const { logs, promise } = runWith(
|
||||
{ health: [], lockPids: [5923, 5923, null], runningPids: [5923] },
|
||||
// Report on every drain poll, so the heartbeat follows the announce.
|
||||
{ drainHeartbeatMs: 0 },
|
||||
);
|
||||
await promise;
|
||||
expect(logs).toEqual([
|
||||
" Finishing all ongoing requests... (run 'kill -9 5923' to force stop)",
|
||||
expect.stringMatching(
|
||||
/^ Still finishing ongoing requests \(\d+s elapsed\)\.\.\. \(run 'kill -9 5923' to force stop\)$/,
|
||||
),
|
||||
]);
|
||||
});
|
||||
|
||||
test("stays silent when the lock is released within the grace window", async () => {
|
||||
const { logs, promise } = runWith(
|
||||
{ health: [], lockPids: [5923, null], runningPids: [5923] },
|
||||
{ drainGraceMs: 1_000 },
|
||||
);
|
||||
await promise;
|
||||
expect(logs).toEqual([]);
|
||||
});
|
||||
|
||||
test("treats a stale lock (dead PID) as released", async () => {
|
||||
// 5923 is not in runningPids, so the recorded owner is dead.
|
||||
const { logs, promise } = runWith({
|
||||
health: [],
|
||||
lockPids: [5923],
|
||||
});
|
||||
await promise;
|
||||
expect(logs).toEqual([]);
|
||||
});
|
||||
|
||||
test("fails when the daemon keeps answering health checks", async () => {
|
||||
const { logs, promise } = runWith(
|
||||
{ health: [true], lockPids: [null] },
|
||||
{ healthTimeoutMs: 0 },
|
||||
);
|
||||
await expect(promise).rejects.toThrow(/did not stop within \d+ seconds/);
|
||||
expect(logs).toEqual([]);
|
||||
});
|
||||
|
||||
test("fails with the holding PID when draining never finishes", async () => {
|
||||
const { promise } = runWith(
|
||||
{ health: [], lockPids: [5923], runningPids: [5923] },
|
||||
{ drainTimeoutMs: 0 },
|
||||
);
|
||||
await expect(promise).rejects.toThrow(
|
||||
/PID 5923.*did not finish its ongoing requests.*kill -9 5923/s,
|
||||
);
|
||||
});
|
||||
|
||||
test("reads the wallet lock file from disk by default", async () => {
|
||||
const dir = makeTempDir();
|
||||
const pidFile = join(dir, "wallet.pid");
|
||||
writeFileSync(pidFile, "1234\n");
|
||||
|
||||
const logs: string[] = [];
|
||||
let polls = 0;
|
||||
await waitForDaemonToExit({
|
||||
pidFilePath: pidFile,
|
||||
isHealthy: () => Promise.resolve(false),
|
||||
isProcessRunning: (pid: number) => pid === 1234,
|
||||
sleep: async () => {
|
||||
// The old daemon exits (and unlinks its lock) after two polls.
|
||||
if (++polls >= 2) rmSync(pidFile);
|
||||
},
|
||||
log: (message: string) => logs.push(message),
|
||||
drainGraceMs: 0,
|
||||
pollIntervalMs: 1,
|
||||
});
|
||||
expect(logs).toEqual([
|
||||
" Finishing all ongoing requests... (run 'kill -9 1234' to force stop)",
|
||||
]);
|
||||
});
|
||||
|
||||
test("treats an unparseable lock file as released", async () => {
|
||||
const dir = makeTempDir();
|
||||
const pidFile = join(dir, "wallet.pid");
|
||||
writeFileSync(pidFile, "starting...");
|
||||
|
||||
const logs: string[] = [];
|
||||
await waitForDaemonToExit({
|
||||
pidFilePath: pidFile,
|
||||
isHealthy: () => Promise.resolve(false),
|
||||
isProcessRunning: () => true,
|
||||
sleep: () => Promise.resolve(),
|
||||
log: (message: string) => logs.push(message),
|
||||
drainTimeoutMs: 5_000,
|
||||
pollIntervalMs: 1,
|
||||
});
|
||||
expect(logs).toEqual([]);
|
||||
});
|
||||
});
|
||||
Reference in New Issue
Block a user