diff --git a/packages/cli/src/commands/daemon/local-daemon.ts b/packages/cli/src/commands/daemon/local-daemon.ts index f2c92ad1d..86e06fa47 100644 --- a/packages/cli/src/commands/daemon/local-daemon.ts +++ b/packages/cli/src/commands/daemon/local-daemon.ts @@ -1,5 +1,5 @@ import { spawn, spawnSync } from "node:child_process"; -import { existsSync, readFileSync } from "node:fs"; +import { appendFileSync, existsSync, readFileSync } from "node:fs"; import { createRequire } from "node:module"; import path from "node:path"; import { loadConfig, resolvePaseoHome } from "@getpaseo/server"; @@ -64,6 +64,7 @@ const DETACHED_STARTUP_GRACE_MS = 1200; const PID_POLL_INTERVAL_MS = 100; const KILL_TIMEOUT_MS = 3000; const DAEMON_LOG_FILENAME = "daemon.log"; +const DAEMON_LAUNCH_LOG_FILENAME = "daemon-launch.log"; const DAEMON_PID_FILENAME = "paseo.pid"; export const DEFAULT_STOP_TIMEOUT_MS = 15_000; @@ -114,6 +115,24 @@ function buildChildEnv(options: DaemonStartOptions): NodeJS.ProcessEnv { return childEnv; } +function appendLaunchLog(home: string, message: string, details?: Record): void { + const line = [ + new Date().toISOString(), + "[CLI daemon]", + `pid=${process.pid}`, + message, + details ? JSON.stringify(details) : "", + ] + .filter((part) => part.length > 0) + .join(" "); + + try { + appendFileSync(path.join(home, DAEMON_LAUNCH_LOG_FILENAME), `${line}\n`, "utf-8"); + } catch { + // Keep launch debugging best-effort so daemon startup behavior is unchanged. + } +} + function resolveDaemonRunnerEntry(): string { const serverExportPath = require.resolve("@getpaseo/server"); let currentDir = path.dirname(serverExportPath); @@ -354,6 +373,14 @@ export async function startLocalDaemonDetached( const paseoHome = resolvePaseoHome(childEnv); const logPath = path.join(paseoHome, DAEMON_LOG_FILENAME); const daemonRunnerEntry = resolveDaemonRunnerEntry(); + appendLaunchLog(paseoHome, "starting detached daemon", { + execPath: process.execPath, + execArgv: process.execArgv, + daemonRunnerEntry, + runnerArgs: buildRunnerArgs(options), + listen: childEnv.PASEO_LISTEN ?? null, + allowedHosts: childEnv.PASEO_ALLOWED_HOSTS ?? null, + }); const child = spawn( process.execPath, [...process.execArgv, daemonRunnerEntry, ...buildRunnerArgs(options)], @@ -364,6 +391,12 @@ export async function startLocalDaemonDetached( }, ); + appendLaunchLog(paseoHome, "detached spawn returned", { + childPid: child.pid ?? null, + spawnfile: child.spawnfile, + spawnargs: child.spawnargs, + }); + child.unref(); const startup = await new Promise((resolve) => { @@ -378,16 +411,33 @@ export async function startLocalDaemonDetached( const timer = setTimeout(() => finish(startupReady()), DETACHED_STARTUP_GRACE_MS); child.once("error", (error) => { + appendLaunchLog(paseoHome, "detached child emitted error during grace period", { + childPid: child.pid ?? null, + message: error.message, + }); clearTimeout(timer); finish(startupExited({ code: null, signal: null, error })); }); child.once("exit", (code, signal) => { + appendLaunchLog(paseoHome, "detached child emitted exit during grace period", { + childPid: child.pid ?? null, + code, + signal, + }); clearTimeout(timer); finish(startupExited({ code, signal })); }); }); + appendLaunchLog(paseoHome, "detached startup grace period completed", { + childPid: child.pid ?? null, + exitedEarly: startup.exitedEarly, + code: startup.exitedEarly ? startup.code : null, + signal: startup.exitedEarly ? startup.signal : null, + error: startup.exitedEarly ? startup.error?.message ?? null : null, + }); + if (startup.exitedEarly) { const reason = startup.error ? startup.error.message diff --git a/packages/desktop/src/daemon/daemon-manager.ts b/packages/desktop/src/daemon/daemon-manager.ts index 57e1f79ad..b70656115 100644 --- a/packages/desktop/src/daemon/daemon-manager.ts +++ b/packages/desktop/src/daemon/daemon-manager.ts @@ -1,5 +1,5 @@ import { spawn, type ChildProcess } from "node:child_process"; -import { existsSync, readFileSync } from "node:fs"; +import { appendFileSync, existsSync, readFileSync } from "node:fs"; import path from "node:path"; import { app, ipcMain } from "electron"; import { loadConfig, resolvePaseoHome, getOrCreateServerId } from "@getpaseo/server"; @@ -27,6 +27,7 @@ const STOP_TIMEOUT_MS = 15_000; const KILL_TIMEOUT_MS = 3_000; const DETACHED_STARTUP_GRACE_MS = 1200; const DEFAULT_ELECTRON_DEV_SERVER_URL = "http://localhost:8081"; +const DAEMON_LAUNCH_LOG_FILENAME = "daemon-launch.log"; type DesktopDaemonState = "starting" | "running" | "stopped" | "errored"; @@ -75,6 +76,10 @@ function logFilePath(): string { return path.join(getPaseoHome(), DAEMON_LOG_FILENAME); } +function launchLogFilePath(): string { + return path.join(getPaseoHome(), DAEMON_LAUNCH_LOG_FILENAME); +} + function isProcessRunning(pid: number): boolean { try { process.kill(pid, 0); @@ -140,6 +145,24 @@ function tailFile(filePath: string, lines = 50): string { } } +function appendLaunchLog(message: string, details?: Record): void { + const line = [ + new Date().toISOString(), + "[desktop daemon]", + `pid=${process.pid}`, + message, + details ? JSON.stringify(details) : "", + ] + .filter((part) => part.length > 0) + .join(" "); + + try { + appendFileSync(launchLogFilePath(), `${line}\n`, "utf-8"); + } catch { + // Keep launch debugging best-effort so desktop startup behavior is unchanged. + } +} + function buildDesktopDaemonCorsOriginsEnv(): string | undefined { const origins = new Set( (process.env.PASEO_CORS_ORIGINS ?? "") @@ -303,6 +326,16 @@ async function startDaemon(): Promise { }, }); + appendLaunchLog("starting detached daemon", { + appIsPackaged: app.isPackaged, + daemonRunnerEntry: daemonRunner.entryPath, + daemonRunnerExecArgv: daemonRunner.execArgv, + command: invocation.command, + args: invocation.args, + listen: process.env.PASEO_LISTEN ?? null, + corsOrigins: corsOrigins ?? null, + }); + const child: ChildProcess = spawn( invocation.command, invocation.args, @@ -313,6 +346,12 @@ async function startDaemon(): Promise { }, ); + appendLaunchLog("detached spawn returned", { + childPid: child.pid ?? null, + spawnfile: child.spawnfile, + spawnargs: child.spawnargs, + }); + child.unref(); // Wait for process to survive the grace period @@ -327,15 +366,26 @@ async function startDaemon(): Promise { const timer = setTimeout(() => finish(false), DETACHED_STARTUP_GRACE_MS); child.once("error", () => { + appendLaunchLog("detached child emitted error during grace period", { + childPid: child.pid ?? null, + }); clearTimeout(timer); finish(true); }); child.once("exit", () => { + appendLaunchLog("detached child emitted exit during grace period", { + childPid: child.pid ?? null, + }); clearTimeout(timer); finish(true); }); }); + appendLaunchLog("detached startup grace period completed", { + childPid: child.pid ?? null, + exitedEarly, + }); + if (exitedEarly) { const logs = tailFile(logFilePath(), 15); throw new Error(`Daemon failed to start.${logs ? `\n\nRecent logs:\n${logs}` : ""}`); @@ -344,6 +394,15 @@ async function startDaemon(): Promise { // Poll for PID file with server ID for (let attempt = 0; attempt < STARTUP_POLL_MAX_ATTEMPTS; attempt++) { const status = resolveStatus(); + if (attempt === 0 || attempt === STARTUP_POLL_MAX_ATTEMPTS - 1 || attempt % 10 === 9) { + appendLaunchLog("polling daemon status after detached start", { + attempt: attempt + 1, + status: status.status, + pid: status.pid, + listen: status.listen, + serverId: status.serverId || null, + }); + } if (status.status === "running" && status.serverId) return status; await sleep(STARTUP_POLL_INTERVAL_MS); } diff --git a/packages/server/scripts/daemon-runner.ts b/packages/server/scripts/daemon-runner.ts index db6d660e2..fc02ceaac 100644 --- a/packages/server/scripts/daemon-runner.ts +++ b/packages/server/scripts/daemon-runner.ts @@ -1,5 +1,5 @@ import { fileURLToPath } from "url"; -import { existsSync } from "node:fs"; +import { appendFileSync, existsSync } from "node:fs"; import path from "node:path"; import { loadConfig } from "../src/server/config.js"; import { acquirePidLock, PidLockError, releasePidLock } from "../src/server/pid-lock.js"; @@ -68,6 +68,28 @@ function resolvePackagedNodeEntrypointRunnerPath(currentScriptPath: string): str return existsSync(runnerPath) ? runnerPath : null; } +function appendLaunchLog( + launchLogPath: string, + message: string, + details?: Record, +): void { + const line = [ + new Date().toISOString(), + "[DaemonRunner]", + `pid=${process.pid}`, + message, + details ? JSON.stringify(details) : "", + ] + .filter((part) => part.length > 0) + .join(" "); + + try { + appendFileSync(launchLogPath, `${line}\n`, "utf-8"); + } catch { + // Keep launch debugging best-effort so daemon startup behavior is unchanged. + } +} + async function main(): Promise { const config = parseConfig(process.argv.slice(2)); const workerEntry = config.devMode ? resolveDevWorkerEntry() : resolveWorkerEntry(); @@ -84,14 +106,34 @@ async function main(): Promise { applySherpaLoaderEnv(workerEnv); const paseoHome = resolvePaseoHome(workerEnv); + const launchLogPath = path.join(paseoHome, "daemon-launch.log"); const daemonConfig = loadConfig(paseoHome, { env: workerEnv }); + appendLaunchLog(launchLogPath, "daemon runner starting", { + argv: process.argv.slice(2), + execPath: process.execPath, + execArgv: process.execArgv, + workerEntry, + workerExecArgv, + devMode: config.devMode, + listen: daemonConfig.listen, + packagedNodeEntrypointRunner, + }); + try { await acquirePidLock(paseoHome, daemonConfig.listen, { ownerPid: process.pid, }); + appendLaunchLog(launchLogPath, "pid lock acquired", { + ownerPid: process.pid, + listen: daemonConfig.listen, + }); } catch (error) { if (error instanceof PidLockError) { + appendLaunchLog(launchLogPath, "pid lock acquisition failed", { + message: error.message, + existingLock: error.existingLock, + }); process.stderr.write(`${error.message}\n`); process.exit(1); return; @@ -105,6 +147,9 @@ async function main(): Promise { return; } lockReleased = true; + appendLaunchLog(launchLogPath, "releasing pid lock", { + ownerPid: process.pid, + }); await releasePidLock(paseoHome, { ownerPid: process.pid, }); @@ -112,6 +157,7 @@ async function main(): Promise { runSupervisor({ name: "DaemonRunner", + launchLogPath, startupMessage: config.devMode ? "Starting daemon worker (dev mode, crash restarts enabled)" : "Starting daemon worker (IPC restart enabled)", diff --git a/packages/server/scripts/supervisor.ts b/packages/server/scripts/supervisor.ts index b661371ab..bc863f75b 100644 --- a/packages/server/scripts/supervisor.ts +++ b/packages/server/scripts/supervisor.ts @@ -1,4 +1,5 @@ import { fork, spawn, type ChildProcess } from "child_process"; +import { appendFileSync } from "node:fs"; type WorkerLifecycleMessage = | { @@ -12,6 +13,7 @@ type WorkerLifecycleMessage = type SupervisorOptions = { name: string; startupMessage: string; + launchLogPath?: string; resolveWorkerEntry: () => string; workerArgs?: string[]; workerEnv?: NodeJS.ProcessEnv; @@ -63,6 +65,28 @@ export function runSupervisor(options: SupervisorOptions): void { process.stderr.write(`[${options.name}] ${message}\n`); }; + const logLaunch = (message: string, details?: Record): void => { + if (!options.launchLogPath) { + return; + } + + const line = [ + new Date().toISOString(), + `[${options.name}]`, + `pid=${process.pid}`, + message, + details ? JSON.stringify(details) : "", + ] + .filter((part) => part.length > 0) + .join(" "); + + try { + appendFileSync(options.launchLogPath, `${line}\n`, "utf-8"); + } catch { + // Keep launch debugging best-effort so daemon startup behavior is unchanged. + } + }; + const exitSupervisor = (code: number): void => { if (exiting) { return; @@ -92,11 +116,22 @@ export function runSupervisor(options: SupervisorOptions): void { const spawnSpec = resolveWorkerSpawnSpec?.(workerEntry) ?? null; if (spawnSpec) { + logLaunch("spawning worker via explicit spawn spec", { + workerEntry, + command: spawnSpec.command, + args: spawnSpec.args, + workerArgs, + }); child = spawn(spawnSpec.command, spawnSpec.args, { stdio: ["inherit", "inherit", "inherit", "ipc"], env: spawnSpec.env ?? workerEnv, }); } else { + logLaunch("spawning worker via fork", { + workerEntry, + workerArgs, + workerExecArgv, + }); child = fork(workerEntry, workerArgs, { stdio: "inherit", env: workerEnv, @@ -104,8 +139,35 @@ export function runSupervisor(options: SupervisorOptions): void { }); } + logLaunch("worker spawn returned", { + childPid: child.pid ?? null, + connected: child.connected, + spawnfile: child.spawnfile, + spawnargs: child.spawnargs, + }); + + child.on("spawn", () => { + logLaunch("worker emitted spawn", { + childPid: child?.pid ?? null, + }); + }); + + child.on("error", (error) => { + logLaunch("worker emitted error", { + childPid: child?.pid ?? null, + message: error.message, + }); + }); + child.on("message", (msg: unknown) => { const lifecycleMessage = parseLifecycleMessage(msg); + logLaunch("worker emitted ipc message", { + childPid: child?.pid ?? null, + rawType: + typeof msg === "object" && msg !== null && "type" in msg + ? (msg as { type?: unknown }).type + : typeof msg, + }); if (!lifecycleMessage) { return; } @@ -119,6 +181,13 @@ export function runSupervisor(options: SupervisorOptions): void { }); child.on("exit", (code, signal) => { + logLaunch("worker emitted exit", { + childPid: child?.pid ?? null, + code, + signal, + restarting, + shuttingDown, + }); const exitDescriptor = describeExit(code, signal); if (shuttingDown) { @@ -137,6 +206,20 @@ export function runSupervisor(options: SupervisorOptions): void { log(`Worker exited (${exitDescriptor}). Supervisor exiting.`); exitSupervisor(typeof code === "number" ? code : 0); }); + + child.on("close", (code, signal) => { + logLaunch("worker emitted close", { + childPid: child?.pid ?? null, + code, + signal, + }); + }); + + child.on("disconnect", () => { + logLaunch("worker emitted disconnect", { + childPid: child?.pid ?? null, + }); + }); }; const requestRestart = (reason: string) => { @@ -169,6 +252,12 @@ export function runSupervisor(options: SupervisorOptions): void { process.on("SIGINT", () => forwardSignal("SIGINT")); process.on("SIGTERM", () => forwardSignal("SIGTERM")); + logLaunch("supervisor starting", { + startupMessage: options.startupMessage, + restartOnCrash, + workerArgs, + workerExecArgv, + }); process.stdout.write(`[${options.name}] ${options.startupMessage}\n`); spawnWorker(); }