Improve daemon startup progress visibility

This commit is contained in:
redshift
2026-07-28 20:52:01 +01:00
parent af3bd832a5
commit 04f8c22085
3 changed files with 204 additions and 7 deletions
+11
View File
@@ -33,6 +33,13 @@ function makeSdkLogger(prefix?: string): SdkLogger {
};
}
const daemonSdkLogger: SdkLogger = makeSdkLogger();
const STARTUP_LOG_PREFIX = "[routstrd:start]";
function startupProgress(message: string): void {
logger.info(message);
console.log(`${STARTUP_LOG_PREFIX} ${message}`);
}
import { parseArgs } from "./args";
import { ensureDirs, loadDaemonConfig, loadDaemonConfigSync, saveDaemonConfig } from "./config-store";
import {
@@ -61,6 +68,7 @@ process.on("unhandledRejection", (reason) => {
});
async function main(): Promise<void> {
startupProgress("Loading configuration...");
const args = parseArgs(process.argv);
const config = await loadDaemonConfig();
@@ -84,6 +92,7 @@ async function main(): Promise<void> {
const updatedConfig = { ...config, port, host, provider };
saveDaemonConfig(updatedConfig);
startupProgress("Opening Routstr databases...");
const sqliteDriver = await createBunSqliteDriver(DB_PATH, { logger: daemonSdkLogger });
const { store, hydrate } = createSdkStore({ driver: sqliteDriver });
await hydrate;
@@ -94,6 +103,7 @@ async function main(): Promise<void> {
const discoveryAdapter = await createShardedDiscoveryAdapter({ driver: sqliteDriver });
const storageAdapter = createStorageAdapterFromStore(store);
startupProgress("Routstr databases ready.");
const modelManager = new ModelManager(discoveryAdapter, {
logger: daemonSdkLogger,
eventStoreDbPath: `${CONFIG_DIR}/events.db`,
@@ -305,6 +315,7 @@ async function main(): Promise<void> {
process.once("SIGINT", shutdownForSignal);
process.once("SIGTERM", shutdownForSignal);
startupProgress("Starting HTTP server...");
server.listen(port, host, async () => {
logger.log(`Routstr daemon listening on http://${host}:${port}/v1`);
if (requestResponseLogDir) {
+87 -1
View File
@@ -1,5 +1,5 @@
import { initializeCoco, getEncodedToken } from "@cashu/coco-core";
import type { HistoryEntry } from "@cashu/coco-core";
import type { HistoryEntry, Logger as CocoLogger } from "@cashu/coco-core";
import { SqliteRepositories } from "@cashu/coco-sqlite-bun";
import { Database } from "bun:sqlite";
import {
@@ -81,6 +81,71 @@ interface CocodConfig {
encrypted: boolean;
}
const STARTUP_LOG_PREFIX = "[routstrd:start]";
function startupProgress(message: string): void {
logger.info(message);
// The daemon is detached and stdout is captured by start-daemon.ts. The
// prefix lets the CLI surface only safe, user-facing startup progress while
// the full diagnostic stream remains in the normal log file.
console.log(`${STARTUP_LOG_PREFIX} ${message}`);
}
const SAFE_COCO_LOG_FIELDS = new Set([
"module",
"mintUrl",
"operationId",
"quoteId",
"state",
"count",
"total",
"filterCount",
"subId",
"initOperations",
"executingOperations",
"pendingOperations",
"rollingBackOperations",
"orphanedReservations",
]);
function safeCocoMetadata(values: unknown[]): Record<string, unknown> {
const safe: Record<string, unknown> = {};
for (const value of values) {
if (!value || typeof value !== "object" || Array.isArray(value)) continue;
for (const [key, fieldValue] of Object.entries(value)) {
if (SAFE_COCO_LOG_FIELDS.has(key)) safe[key] = fieldValue;
}
}
return safe;
}
function createCocoLogger(bindings: Record<string, unknown> = {}): CocoLogger {
const write = (
level: "error" | "warn" | "info" | "debug",
message: string,
meta: unknown[],
) => {
// Coco diagnostics may contain proof secrets or encoded tokens. Keep only
// an explicit metadata allowlist; startup counts and operation IDs remain
// useful without copying wallet material into routstrd's logs.
const metadata = safeCocoMetadata([bindings, ...meta]);
logger[level](
`[coco] ${message}`,
...(Object.keys(metadata).length > 0 ? [metadata] : []),
);
};
return {
error: (message, ...meta) => write("error", message, meta),
warn: (message, ...meta) => write("warn", message, meta),
info: (message, ...meta) => write("info", message, meta),
debug: (message, ...meta) => write("debug", message, meta),
log: (level, message, ...meta) => write(level, message, meta),
child: (childBindings) =>
createCocoLogger({ ...bindings, ...childBindings }),
};
}
function loadMnemonic(configFile: string = CONFIG_FILE): string {
if (!existsSync(configFile)) {
throw new Error(
@@ -410,6 +475,8 @@ export async function createCocoClient(
let coco: Awaited<ReturnType<typeof initializeCoco>> | undefined;
try {
startupProgress("Opening Cashu wallet database...");
// Read and validate the existing cocod config during startup rather than
// deferring failure until coco-core first needs wallet key material.
const seed = mnemonicToSeedSync(loadMnemonic(configFile));
@@ -417,10 +484,29 @@ export async function createCocoClient(
const repo = new SqliteRepositories({ database });
await repo.init();
const [pendingSends, inflightProofs, pendingMints] = await Promise.all([
repo.sendOperationRepository.getPending(),
repo.proofRepository.getInflightProofs(),
repo.mintOperationRepository.getPending(),
]);
const recoveryCount =
pendingSends.length + inflightProofs.length + pendingMints.length;
if (recoveryCount > 0) {
startupProgress(
`Recovering wallet state: ${pendingSends.length} pending sends, ` +
`${inflightProofs.length} in-flight proofs, ${pendingMints.length} pending mints. ` +
"This may take a few minutes while Cashu mints are contacted.",
);
} else {
startupProgress("Initializing Cashu wallet...");
}
coco = await initializeCoco({
repo,
seedGetter: async () => seed,
logger: createCocoLogger(),
});
startupProgress("Cashu wallet ready.");
} catch (error) {
database?.close();
releaseLegacyPidClaim();
+106 -6
View File
@@ -1,4 +1,10 @@
import { openSync, existsSync, readFileSync } from "fs";
import {
closeSync,
existsSync,
fstatSync,
openSync,
readSync,
} from "fs";
import { logger } from "./utils/logger";
import { CONFIG_DIR, LOGS_DIR } from "./utils/config";
import { withCrossProcessLock } from "./utils/process-lock";
@@ -12,11 +18,17 @@ const DEBUG_LOG_PATH = `${CONFIG_DIR}/debug.log`;
* telling the user to go read logs.
*/
function readDaemonOutput(offset: number): string {
let fd: number | undefined;
try {
if (!existsSync(DEBUG_LOG_PATH)) return "";
const content = readFileSync(DEBUG_LOG_PATH, "utf-8");
return content
.slice(offset)
fd = openSync(DEBUG_LOG_PATH, "r");
const size = fstatSync(fd).size;
if (size <= offset) return "";
const bytesToRead = Math.min(size - offset, 256 * 1024);
const buffer = Buffer.allocUnsafe(bytesToRead);
const bytesRead = readSync(fd, buffer, 0, bytesToRead, offset);
return buffer
.toString("utf8", 0, bytesRead)
.split("\n")
.map((line) => line.trim())
.filter(Boolean)
@@ -24,6 +36,69 @@ function readDaemonOutput(offset: number): string {
.join("\n");
} catch {
return "";
} finally {
if (fd !== undefined) closeSync(fd);
}
}
const STARTUP_LOG_PREFIX = "[routstrd:start]";
/**
* Print only explicitly tagged, user-safe progress emitted by the detached
* daemon. Return the next byte offset so each line is shown exactly once.
*/
function printStartupProgress(offset: number): {
offset: number;
lastMessage?: string;
} {
let fd: number | undefined;
try {
if (!existsSync(DEBUG_LOG_PATH)) return { offset };
fd = openSync(DEBUG_LOG_PATH, "r");
const size = fstatSync(fd).size;
if (size <= offset) return { offset };
// Startup messages are short. Bound each read so a noisy daemon cannot
// make the waiting CLI repeatedly load a large debug log into memory.
const bytesToRead = Math.min(size - offset, 64 * 1024);
const buffer = Buffer.allocUnsafe(bytesToRead);
const bytesRead = readSync(fd, buffer, 0, bytesToRead, offset);
const lastNewlineIndex = buffer.subarray(0, bytesRead).lastIndexOf(0x0a);
const completeBytes = lastNewlineIndex + 1;
if (completeBytes === 0) return { offset };
const appended = buffer.toString("utf8", 0, completeBytes);
let lastMessage: string | undefined;
for (const line of appended.split("\n")) {
const markerIndex = line.indexOf(STARTUP_LOG_PREFIX);
if (markerIndex === -1) continue;
const message = line.slice(markerIndex + STARTUP_LOG_PREFIX.length).trim();
if (message) {
console.log(` ${message}`);
lastMessage = message;
}
}
return { offset: offset + completeBytes, lastMessage };
} catch {
return { offset };
} finally {
if (fd !== undefined) closeSync(fd);
}
}
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`;
}
function fileSize(path: string): number {
let fd: number | undefined;
try {
fd = openSync(path, "r");
return fstatSync(fd).size;
} finally {
if (fd !== undefined) closeSync(fd);
}
}
@@ -75,7 +150,7 @@ async function startDaemonUnlocked(
const shellCmd = `bun run "${daemonScript}" ${args.map((a) => `'${a}'`).join(" ")}`;
const debugLogOffset = existsSync(DEBUG_LOG_PATH)
? readFileSync(DEBUG_LOG_PATH, "utf-8").length
? fileSize(DEBUG_LOG_PATH)
: 0;
const debugLogFd = openSync(DEBUG_LOG_PATH, "a");
@@ -93,10 +168,32 @@ async function startDaemonUnlocked(
exitCode = code;
});
const startedAt = Date.now();
const heartbeatIntervalMs = 10_000;
let nextHeartbeatAt = heartbeatIntervalMs;
let progressLogOffset = debugLogOffset;
let currentPhase = "starting daemon";
const maxPolls = Math.ceil(startupTimeoutMs / pollIntervalMs);
for (let i = 0; i < maxPolls; i++) {
await new Promise((resolve) => setTimeout(resolve, pollIntervalMs));
const progress = printStartupProgress(progressLogOffset);
progressLogOffset = progress.offset;
if (progress.lastMessage) {
currentPhase = progress.lastMessage
.replace(/\.$/, "")
.toLowerCase();
}
const elapsedMs = Date.now() - startedAt;
if (elapsedMs >= nextHeartbeatAt) {
console.log(
` Still ${currentPhase} (${formatElapsed(elapsedMs)} elapsed)...`,
);
nextHeartbeatAt += heartbeatIntervalMs;
}
if (exitCode !== null) {
const daemonOutput = readDaemonOutput(debugLogOffset);
throw new Error(
@@ -108,7 +205,10 @@ async function startDaemonUnlocked(
}
if (await isDaemonHealthy(port, ch)) {
console.log(`Routstr daemon started (PID: ${proc.pid}).`);
printStartupProgress(progressLogOffset);
console.log(
`Routstr daemon started (PID: ${proc.pid}, ${formatElapsed(Date.now() - startedAt)}).`,
);
return;
}
}