Add structured backend logging with pino
Wires leveled, structured logging (pretty in dev, JSON in prod) through the server lifecycle, HTTP/WS request handling, run engine, auth, db, and config loading. CLI command output is left untouched since it's user-facing terminal UX, not backend logs. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
@@ -9,6 +9,9 @@ import type { ScriptConfig } from "../config/schema";
|
||||
import { buildInvocation, type Invocation } from "./build-args";
|
||||
import { registerRun, unregisterRun } from "./registry";
|
||||
import { emitRunMessage } from "./events";
|
||||
import { logger } from "../logger";
|
||||
|
||||
const log = logger.child({ mod: "runner" });
|
||||
|
||||
export class ScriptNotFoundError extends Error {}
|
||||
|
||||
@@ -49,9 +52,14 @@ export async function startRun({
|
||||
})
|
||||
.run();
|
||||
|
||||
log.info({ runId, scriptId: script.id, triggeredBy }, "run queued");
|
||||
|
||||
// Fire and forget - the caller gets the runId immediately, progress streams over WS/polling.
|
||||
void executeRun(runId, script, invocation, logFilePath).catch((error) => {
|
||||
console.error(`[runner] unhandled error executing run ${runId}:`, error);
|
||||
log.error(
|
||||
{ runId, scriptId: script.id, err: error },
|
||||
"unhandled error executing run",
|
||||
);
|
||||
});
|
||||
|
||||
return runId;
|
||||
@@ -103,6 +111,11 @@ async function executeRun(
|
||||
|
||||
registerRun({ runId, scriptId: script.id, controller });
|
||||
setStatus("running", { startedAt: new Date() });
|
||||
log.info(
|
||||
{ runId, scriptId: script.id, command: script.command },
|
||||
"run started",
|
||||
);
|
||||
const startedAt = process.hrtime.bigint();
|
||||
|
||||
try {
|
||||
const subprocess = execa(script.command, invocation.argv, {
|
||||
@@ -145,11 +158,26 @@ async function executeRun(
|
||||
? (result.shortMessage ?? null)
|
||||
: null,
|
||||
});
|
||||
const durationMs = Number(process.hrtime.bigint() - startedAt) / 1e6;
|
||||
log[status === "succeeded" ? "info" : "warn"](
|
||||
{
|
||||
runId,
|
||||
scriptId: script.id,
|
||||
status,
|
||||
exitCode: result.exitCode ?? null,
|
||||
durationMs: Math.round(durationMs),
|
||||
},
|
||||
"run finished",
|
||||
);
|
||||
} catch (error) {
|
||||
setStatus("failed", {
|
||||
endedAt: new Date(),
|
||||
errorMessage: (error as Error).message,
|
||||
});
|
||||
log.error(
|
||||
{ runId, scriptId: script.id, err: error },
|
||||
"run failed to execute",
|
||||
);
|
||||
} finally {
|
||||
logStream.end();
|
||||
unregisterRun(runId);
|
||||
@@ -170,7 +198,8 @@ export function reconcileOrphanedRuns() {
|
||||
})
|
||||
.where(eq(runs.status, "running"))
|
||||
.run();
|
||||
db.update(runs)
|
||||
const queued = db
|
||||
.update(runs)
|
||||
.set({
|
||||
status: "interrupted",
|
||||
endedAt: now,
|
||||
@@ -178,5 +207,14 @@ export function reconcileOrphanedRuns() {
|
||||
})
|
||||
.where(eq(runs.status, "queued"))
|
||||
.run();
|
||||
|
||||
const interruptedCount = orphaned.changes + queued.changes;
|
||||
if (interruptedCount > 0) {
|
||||
log.warn(
|
||||
{ runningCount: orphaned.changes, queuedCount: queued.changes },
|
||||
"marked orphaned runs as interrupted after restart",
|
||||
);
|
||||
}
|
||||
|
||||
return orphaned;
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user