From 04f8c220853a0b13a7137cdfd7cfe9041a23ff14 Mon Sep 17 00:00:00 2001 From: redshift <213178690+1ftredsh@users.noreply.github.com> Date: Tue, 28 Jul 2026 20:52:01 +0100 Subject: [PATCH] Improve daemon startup progress visibility --- src/daemon/index.ts | 11 +++ src/daemon/wallet/coco-client.ts | 88 +++++++++++++++++++++++- src/start-daemon.ts | 112 +++++++++++++++++++++++++++++-- 3 files changed, 204 insertions(+), 7 deletions(-) diff --git a/src/daemon/index.ts b/src/daemon/index.ts index 52e1422..91ca8c1 100644 --- a/src/daemon/index.ts +++ b/src/daemon/index.ts @@ -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 { + startupProgress("Loading configuration..."); const args = parseArgs(process.argv); const config = await loadDaemonConfig(); @@ -84,6 +92,7 @@ async function main(): Promise { 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 { 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 { 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) { diff --git a/src/daemon/wallet/coco-client.ts b/src/daemon/wallet/coco-client.ts index 54f36cb..c7dbbae 100644 --- a/src/daemon/wallet/coco-client.ts +++ b/src/daemon/wallet/coco-client.ts @@ -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 { + const safe: Record = {}; + 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 = {}): 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> | 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(); diff --git a/src/start-daemon.ts b/src/start-daemon.ts index c3ac308..6f4629a 100644 --- a/src/start-daemon.ts +++ b/src/start-daemon.ts @@ -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; } }