From 3bbcacb2565c22841884a83c0a01561f4103ce43 Mon Sep 17 00:00:00 2001 From: Benjamin Shafii Date: Wed, 4 Feb 2026 12:54:08 -0800 Subject: [PATCH] feat(headless): improve cross-service observability --- packages/headless/README.md | 14 ++ packages/headless/src/cli.ts | 340 ++++++++++++++++++++++++++++++---- packages/server/src/cli.ts | 27 +-- packages/server/src/config.ts | 52 +++++- packages/server/src/server.ts | 127 ++++++++++++- packages/server/src/types.ts | 4 + 6 files changed, 512 insertions(+), 52 deletions(-) diff --git a/packages/headless/README.md b/packages/headless/README.md index 3cb8e3bd..d48aaa3f 100644 --- a/packages/headless/README.md +++ b/packages/headless/README.md @@ -40,6 +40,20 @@ pnpm --filter openwrk dev -- \ The command prints pairing details (OpenWork server URL + token, OpenCode URL + auth) so remote OpenWork clients can connect. +## Logging + +`openwrk` emits a unified log stream from OpenCode, OpenWork server, and Owpenbot. Use JSON format for +structured, OpenTelemetry-friendly logs and a stable run id for correlation. + +```bash +OPENWRK_LOG_FORMAT=json openwrk start --workspace /path/to/workspace +``` + +Use `--run-id` or `OPENWRK_RUN_ID` to supply your own correlation id. + +OpenWork server logs every request with method, path, status, and duration. Disable this when running +`openwork-server` directly by setting `OPENWORK_LOG_REQUESTS=0` or passing `--no-log-requests`. + ## Router daemon (multi-workspace) The router keeps a single OpenCode process alive and switches workspaces JIT using the `directory` parameter. diff --git a/packages/headless/src/cli.ts b/packages/headless/src/cli.ts index da00f570..aa01827f 100644 --- a/packages/headless/src/cli.ts +++ b/packages/headless/src/cli.ts @@ -15,6 +15,30 @@ import { createOpencodeClient } from "@opencode-ai/sdk/v2/client"; type ApprovalMode = "manual" | "auto"; +type LogFormat = "pretty" | "json"; + +type LogLevel = "debug" | "info" | "warn" | "error"; + +type LogAttributes = Record; + +type LoggerChild = { + log: (level: LogLevel, message: string, attributes?: LogAttributes) => void; + debug: (message: string, attributes?: LogAttributes) => void; + info: (message: string, attributes?: LogAttributes) => void; + warn: (message: string, attributes?: LogAttributes) => void; + error: (message: string, attributes?: LogAttributes) => void; +}; + +type Logger = { + format: LogFormat; + log: (level: LogLevel, message: string, attributes?: LogAttributes, component?: string) => void; + debug: (message: string, attributes?: LogAttributes, component?: string) => void; + info: (message: string, attributes?: LogAttributes, component?: string) => void; + warn: (message: string, attributes?: LogAttributes, component?: string) => void; + error: (message: string, attributes?: LogAttributes, component?: string) => void; + child: (component: string, attributes?: LogAttributes) => LoggerChild; +}; + const FALLBACK_VERSION = "0.1.0"; const DEFAULT_OPENWORK_PORT = 8787; const DEFAULT_OWPENBOT_HEALTH_PORT = 3005; @@ -300,6 +324,20 @@ function readBinarySource( throw new Error(`Invalid ${key} value: ${raw}. Use auto|bundled|downloaded|external.`); } +function readLogFormat( + flags: Map, + key: string, + fallback: LogFormat, + envKey?: string, +): LogFormat { + const raw = readFlag(flags, key) ?? (envKey ? process.env[envKey] : undefined); + if (!raw) return fallback; + const normalized = String(raw).trim().toLowerCase(); + if (normalized === "json") return "json"; + if (normalized === "pretty" || normalized === "text" || normalized === "human") return "pretty"; + throw new Error(`Invalid ${key} value: ${raw}. Use pretty|json.`); +} + async function fileExists(path: string): Promise { try { await stat(path); @@ -466,6 +504,8 @@ function prefixStream( stream: NodeJS.ReadableStream | null, label: string, level: "stdout" | "stderr", + logger: Logger, + pid?: number, ): void { if (!stream) return; stream.setEncoding("utf8"); @@ -476,22 +516,22 @@ function prefixStream( buffer = lines.pop() ?? ""; for (const line of lines) { if (!line.trim()) continue; - const message = `[${label}] ${line}`; - if (level === "stderr") { - console.error(message); - } else { - console.log(message); + if (logger.format === "json" && looksLikeOtelLogLine(line)) { + process.stdout.write(`${line}\n`); + continue; } + const severity: LogLevel = level === "stderr" ? "error" : "info"; + logger.log(severity, line, { stream: level, pid }, label); } }); stream.on("end", () => { if (!buffer.trim()) return; - const message = `[${label}] ${buffer}`; - if (level === "stderr") { - console.error(message); - } else { - console.log(message); + if (logger.format === "json" && looksLikeOtelLogLine(buffer)) { + process.stdout.write(`${buffer}\n`); + return; } + const severity: LogLevel = level === "stderr" ? "error" : "info"; + logger.log(severity, buffer, { stream: level, pid }, label); }); } @@ -1389,6 +1429,8 @@ function printHelp(): void { " --check-events Verify SSE events during check", " --json Output JSON when applicable", " --verbose Print additional diagnostics", + " --log-format Log output format: pretty | json", + " --run-id Correlation id for logs (default: random UUID)", " --help Show help", " --version Show version", ].join("\n"); @@ -1426,6 +1468,9 @@ async function startOpencode(options: { username?: string; password?: string; corsOrigins: string[]; + logger: Logger; + runId: string; + logFormat: LogFormat; }) { const args = ["serve", "--hostname", options.bindHost, "--port", String(options.port)]; for (const origin of options.corsOrigins) { @@ -1439,13 +1484,22 @@ async function startOpencode(options: { ...process.env, OPENCODE_CLIENT: "openwrk", OPENWORK: "1", + OPENWRK_RUN_ID: options.runId, + OPENWRK_LOG_FORMAT: options.logFormat, + OTEL_RESOURCE_ATTRIBUTES: mergeResourceAttributes( + { + "service.name": "opencode", + "service.instance.id": options.runId, + }, + process.env.OTEL_RESOURCE_ATTRIBUTES, + ), ...(options.username ? { OPENCODE_SERVER_USERNAME: options.username } : {}), ...(options.password ? { OPENCODE_SERVER_PASSWORD: options.password } : {}), }, }); - prefixStream(child.stdout, "opencode", "stdout"); - prefixStream(child.stderr, "opencode", "stderr"); + prefixStream(child.stdout, "opencode", "stdout", options.logger, child.pid ?? undefined); + prefixStream(child.stderr, "opencode", "stderr", options.logger, child.pid ?? undefined); return child; } @@ -1466,6 +1520,9 @@ async function startOpenworkServer(options: { opencodeUsername?: string; opencodePassword?: string; owpenbotHealthPort?: number; + logger: Logger; + runId: string; + logFormat: LogFormat; }) { const args = [ "--host", @@ -1504,6 +1561,9 @@ async function startOpenworkServer(options: { if (options.opencodePassword) { args.push("--opencode-password", options.opencodePassword); } + if (options.logFormat) { + args.push("--log-format", options.logFormat); + } const resolved = resolveBinCommand(options.bin); const child = spawn(resolved.command, [...resolved.prefixArgs, ...args], { @@ -1513,6 +1573,16 @@ async function startOpenworkServer(options: { ...process.env, OPENWORK_TOKEN: options.token, OPENWORK_HOST_TOKEN: options.hostToken, + OPENWRK_RUN_ID: options.runId, + OPENWORK_RUN_ID: options.runId, + OPENWORK_LOG_FORMAT: options.logFormat, + OTEL_RESOURCE_ATTRIBUTES: mergeResourceAttributes( + { + "service.name": "openwork-server", + "service.instance.id": options.runId, + }, + process.env.OTEL_RESOURCE_ATTRIBUTES, + ), ...(options.owpenbotHealthPort ? { OWPENBOT_HEALTH_PORT: String(options.owpenbotHealthPort) } : {}), ...(options.opencodeBaseUrl ? { OPENWORK_OPENCODE_BASE_URL: options.opencodeBaseUrl } : {}), ...(options.opencodeDirectory ? { OPENWORK_OPENCODE_DIRECTORY: options.opencodeDirectory } : {}), @@ -1521,8 +1591,8 @@ async function startOpenworkServer(options: { }, }); - prefixStream(child.stdout, "openwork-server", "stdout"); - prefixStream(child.stderr, "openwork-server", "stderr"); + prefixStream(child.stdout, "openwork-server", "stdout", options.logger, child.pid ?? undefined); + prefixStream(child.stderr, "openwork-server", "stderr", options.logger, child.pid ?? undefined); return child; } @@ -1534,6 +1604,9 @@ async function startOwpenbot(options: { opencodeUsername?: string; opencodePassword?: string; owpenbotHealthPort?: number; + logger: Logger; + runId: string; + logFormat: LogFormat; }) { const args = ["start", options.workspace]; if (options.opencodeUrl) { @@ -1549,6 +1622,15 @@ async function startOwpenbot(options: { stdio: ["ignore", "pipe", "pipe"], env: { ...process.env, + OPENWRK_RUN_ID: options.runId, + OPENWRK_LOG_FORMAT: options.logFormat, + OTEL_RESOURCE_ATTRIBUTES: mergeResourceAttributes( + { + "service.name": "owpenbot", + "service.instance.id": options.runId, + }, + process.env.OTEL_RESOURCE_ATTRIBUTES, + ), ...(options.opencodeUrl ? { OPENCODE_URL: options.opencodeUrl } : {}), OPENCODE_DIRECTORY: options.workspace, ...(options.owpenbotHealthPort ? { OWPENBOT_HEALTH_PORT: String(options.owpenbotHealthPort) } : {}), @@ -1557,8 +1639,8 @@ async function startOwpenbot(options: { }, }); - prefixStream(child.stdout, "owpenbot", "stdout"); - prefixStream(child.stderr, "owpenbot", "stderr"); + prefixStream(child.stdout, "owpenbot", "stdout", options.logger, child.pid ?? undefined); + prefixStream(child.stderr, "owpenbot", "stderr", options.logger, child.pid ?? undefined); return child; } @@ -1781,13 +1863,127 @@ function outputError(error: unknown, json: boolean): void { console.error(message); } -function createVerboseLogger(enabled: boolean) { +function createVerboseLogger(enabled: boolean, logger?: Logger, component = "openwrk") { return (message: string) => { if (!enabled) return; - console.log(`[openwrk] ${message}`); + if (logger) { + logger.debug(message, undefined, component); + return; + } + console.log(`[${component}] ${message}`); }; } +const LOG_LEVEL_NUMBERS: Record = { + debug: 5, + info: 9, + warn: 13, + error: 17, +}; + +function toUnixNano(): string { + return (BigInt(Date.now()) * 1_000_000n).toString(); +} + +function mergeResourceAttributes(additional: Record, existing?: string): string { + const entries = new Map(); + if (existing) { + for (const part of existing.split(",")) { + const trimmed = part.trim(); + if (!trimmed) continue; + const [key, ...rest] = trimmed.split("="); + if (!key || rest.length === 0) continue; + entries.set(key, rest.join("=").replace(/,/g, ";")); + } + } + for (const [key, value] of Object.entries(additional)) { + if (!key) continue; + if (value === undefined || value === null) continue; + entries.set(key, String(value).replace(/,/g, ";")); + } + return Array.from(entries.entries()) + .map(([key, value]) => `${key}=${value}`) + .join(","); +} + +function createLogger(options: { + format: LogFormat; + runId: string; + serviceName: string; + serviceVersion?: string; +}): Logger { + const host = hostname().trim(); + const resource: Record = { + "service.name": options.serviceName, + "service.instance.id": options.runId, + }; + if (options.serviceVersion) { + resource["service.version"] = options.serviceVersion; + } + if (host) { + resource["host.name"] = host; + } + const baseAttributes: LogAttributes = { + "run.id": options.runId, + "process.pid": process.pid, + }; + + const emit = (level: LogLevel, message: string, attributes?: LogAttributes, component?: string) => { + const mergedAttributes: LogAttributes = { + ...baseAttributes, + ...(component ? { "service.component": component } : {}), + ...(attributes ?? {}), + }; + if (options.format === "json") { + const record = { + timeUnixNano: toUnixNano(), + severityText: level.toUpperCase(), + severityNumber: LOG_LEVEL_NUMBERS[level], + body: message, + attributes: mergedAttributes, + resource, + }; + process.stdout.write(`${JSON.stringify(record)}\n`); + return; + } + const label = component ?? options.serviceName; + const levelTag = level === "info" ? "" : ` ${level.toUpperCase()}`; + const tag = label ? `${`[${label}]`}${levelTag}` : levelTag.trim(); + const line = tag ? `${tag} ${message}` : message; + process.stdout.write(`${line}\n`); + }; + + const child = (component: string, attributes?: LogAttributes): LoggerChild => ({ + log: (level, message, attrs) => emit(level, message, { ...(attributes ?? {}), ...(attrs ?? {}) }, component), + debug: (message, attrs) => emit("debug", message, { ...(attributes ?? {}), ...(attrs ?? {}) }, component), + info: (message, attrs) => emit("info", message, { ...(attributes ?? {}), ...(attrs ?? {}) }, component), + warn: (message, attrs) => emit("warn", message, { ...(attributes ?? {}), ...(attrs ?? {}) }, component), + error: (message, attrs) => emit("error", message, { ...(attributes ?? {}), ...(attrs ?? {}) }, component), + }); + + return { + format: options.format, + log: emit, + debug: (message, attrs, component) => emit("debug", message, attrs, component), + info: (message, attrs, component) => emit("info", message, attrs, component), + warn: (message, attrs, component) => emit("warn", message, attrs, component), + error: (message, attrs, component) => emit("error", message, attrs, component), + child, + }; +} + +function looksLikeOtelLogLine(line: string): boolean { + const trimmed = line.trim(); + if (!trimmed.startsWith("{") || !trimmed.endsWith("}")) return false; + try { + const parsed = JSON.parse(trimmed) as Record; + if (!parsed || typeof parsed !== "object") return false; + return typeof parsed.timeUnixNano === "string" && typeof parsed.severityText === "string"; + } catch { + return false; + } +} + async function spawnRouterDaemon(args: ParsedArgs, dataDir: string, host: string, port: number) { const self = resolveSelfCommand(); const commandArgs = [ @@ -1813,6 +2009,8 @@ async function spawnRouterDaemon(args: ParsedArgs, dataDir: string, host: string const sidecarSource = readFlag(args.flags, "sidecar-source") ?? process.env.OPENWRK_SIDECAR_SOURCE; const opencodeSource = readFlag(args.flags, "opencode-source") ?? process.env.OPENWRK_OPENCODE_SOURCE; const verbose = readBool(args.flags, "verbose", false, "OPENWRK_VERBOSE"); + const logFormat = readFlag(args.flags, "log-format") ?? process.env.OPENWRK_LOG_FORMAT; + const runId = readFlag(args.flags, "run-id") ?? process.env.OPENWRK_RUN_ID; if (opencodeBin) commandArgs.push("--opencode-bin", opencodeBin); if (opencodeHost) commandArgs.push("--opencode-host", opencodeHost); @@ -1825,6 +2023,8 @@ async function spawnRouterDaemon(args: ParsedArgs, dataDir: string, host: string if (sidecarSource) commandArgs.push("--sidecar-source", sidecarSource); if (opencodeSource) commandArgs.push("--opencode-source", opencodeSource); if (verbose) commandArgs.push("--verbose"); + if (logFormat) commandArgs.push("--log-format", String(logFormat)); + if (runId) commandArgs.push("--run-id", String(runId)); const child = spawn(self.command, commandArgs, { detached: true, @@ -1995,7 +2195,16 @@ async function runInstanceCommand(args: ParsedArgs) { async function runRouterDaemon(args: ParsedArgs) { const outputJson = readBool(args.flags, "json", false); const verbose = readBool(args.flags, "verbose", false, "OPENWRK_VERBOSE"); - const logVerbose = createVerboseLogger(verbose && !outputJson); + const logFormat = readLogFormat(args.flags, "log-format", "pretty", "OPENWRK_LOG_FORMAT"); + const runId = readFlag(args.flags, "run-id") ?? process.env.OPENWRK_RUN_ID ?? randomUUID(); + const cliVersion = await resolveCliVersion(); + const logger = createLogger({ + format: logFormat, + runId, + serviceName: "openwrk", + serviceVersion: cliVersion, + }); + const logVerbose = createVerboseLogger(verbose && !outputJson, logger, "openwrk"); const sidecarSource = readBinarySource(args.flags, "sidecar-source", "auto", "OPENWRK_SIDECAR_SOURCE"); const opencodeSource = readBinarySource(args.flags, "opencode-source", "auto", "OPENWRK_OPENCODE_SOURCE"); const dataDir = resolveRouterDataDir(args.flags); @@ -2033,8 +2242,12 @@ async function runRouterDaemon(args: ParsedArgs) { const activeWorkspace = state.workspaces.find((entry) => entry.id === state.activeId && entry.workspaceType === "local"); const opencodeWorkdir = opencodeWorkdirFlag ?? activeWorkspace?.path ?? process.cwd(); const resolvedWorkdir = await ensureWorkspace(opencodeWorkdir); + logger.info( + "Daemon starting", + { runId, logFormat, workdir: resolvedWorkdir, host, port }, + "openwrk", + ); - const cliVersion = await resolveCliVersion(); const sidecar = resolveSidecarConfig(args.flags, cliVersion); const allowExternal = readBool(args.flags, "allow-external", false, "OPENWRK_ALLOW_EXTERNAL"); const manifest = await readVersionManifest(); @@ -2112,15 +2325,21 @@ async function runRouterDaemon(args: ParsedArgs) { username: opencodePassword ? opencodeUsername : undefined, password: opencodePassword, corsOrigins: corsOrigins.length ? corsOrigins : ["*"], + logger, + runId, + logFormat, }); opencodeChild = child; + logger.info("Process spawned", { pid: child.pid ?? 0 }, "opencode"); const baseUrl = `http://${opencodeHost}:${opencodePort}`; const client = createOpencodeClient({ baseUrl, directory: resolvedWorkdir, headers: authHeaders, }); + logger.info("Waiting for health", { url: baseUrl }, "opencode"); await waitForOpencodeHealthy(client); + logger.info("Healthy", { url: baseUrl }, "opencode"); state.opencode = { pid: child.pid ?? 0, port: opencodePort, @@ -2135,6 +2354,22 @@ async function runRouterDaemon(args: ParsedArgs) { await ensureOpencode(); const server = createHttpServer(async (req, res) => { + const startedAt = Date.now(); + const method = req.method ?? "GET"; + const url = new URL(req.url ?? "/", `http://${host}:${port}`); + res.on("finish", () => { + logger.info( + "Router request", + { + method, + path: url.pathname, + status: res.statusCode, + durationMs: Date.now() - startedAt, + activeId: state.activeId, + }, + "openwrk-router", + ); + }); res.setHeader("Access-Control-Allow-Origin", "*"); res.setHeader("Access-Control-Allow-Methods", "GET,POST,OPTIONS"); res.setHeader("Access-Control-Allow-Headers", "Content-Type"); @@ -2144,8 +2379,6 @@ async function runRouterDaemon(args: ParsedArgs) { res.end(); return; } - - const url = new URL(req.url ?? "/", `http://${host}:${port}`); const parts = url.pathname.split("/").filter(Boolean); const send = (status: number, payload: unknown) => { @@ -2328,6 +2561,7 @@ async function runRouterDaemon(args: ParsedArgs) { }); const shutdown = async () => { + logger.info("Daemon shutting down", { host, port }, "openwrk-router"); try { await new Promise((resolve) => server.close(() => resolve())); } catch { @@ -2358,7 +2592,11 @@ async function runRouterDaemon(args: ParsedArgs) { if (outputJson) { outputResult({ ok: true, daemon: state.daemon }, true); } else { - console.log(`openwrk daemon running on ${host}:${port}`); + if (logFormat === "json") { + logger.info("Daemon running", { host, port }, "openwrk-router"); + } else { + console.log(`openwrk daemon running on ${host}:${port}`); + } } }); @@ -2479,12 +2717,22 @@ async function runStart(args: ParsedArgs) { const checkOnly = readBool(args.flags, "check", false); const checkEvents = readBool(args.flags, "check-events", false); const verbose = readBool(args.flags, "verbose", false, "OPENWRK_VERBOSE"); - const logVerbose = createVerboseLogger(verbose && !outputJson); + const logFormat = readLogFormat(args.flags, "log-format", "pretty", "OPENWRK_LOG_FORMAT"); + const runId = readFlag(args.flags, "run-id") ?? process.env.OPENWRK_RUN_ID ?? randomUUID(); + const cliVersion = await resolveCliVersion(); + const logger = createLogger({ + format: logFormat, + runId, + serviceName: "openwrk", + serviceVersion: cliVersion, + }); + const logVerbose = createVerboseLogger(verbose && !outputJson, logger, "openwrk"); const sidecarSource = readBinarySource(args.flags, "sidecar-source", "auto", "OPENWRK_SIDECAR_SOURCE"); const opencodeSource = readBinarySource(args.flags, "opencode-source", "auto", "OPENWRK_OPENCODE_SOURCE"); const workspace = readFlag(args.flags, "workspace") ?? process.env.OPENWORK_WORKSPACE ?? process.cwd(); const resolvedWorkspace = await ensureWorkspace(workspace); + logger.info("Run starting", { workspace: resolvedWorkspace, logFormat, runId }, "openwrk"); const explicitOpencodeBin = readFlag(args.flags, "opencode-bin") ?? process.env.OPENWORK_OPENCODE_BIN; const opencodeBindHost = readFlag(args.flags, "opencode-host") ?? process.env.OPENWORK_OPENCODE_BIND_HOST ?? "0.0.0.0"; @@ -2528,7 +2776,6 @@ async function runStart(args: ParsedArgs) { const corsOrigins = parseList(corsValue); const connectHost = readFlag(args.flags, "connect-host"); - const cliVersion = await resolveCliVersion(); const sidecar = resolveSidecarConfig(args.flags, cliVersion); const manifest = await readVersionManifest(); const allowExternal = readBool(args.flags, "allow-external", false, "OPENWRK_ALLOW_EXTERNAL"); @@ -2587,19 +2834,20 @@ async function runStart(args: ParsedArgs) { const shutdown = async () => { if (shuttingDown) return; shuttingDown = true; + logger.info("Shutting down", { children: children.map((handle) => handle.name) }, "openwrk"); await Promise.all(children.map((handle) => stopChild(handle.child))); }; const handleExit = (name: string, code: number | null, signal: NodeJS.Signals | null) => { if (shuttingDown) return; const reason = code !== null ? `code ${code}` : signal ? `signal ${signal}` : "unknown"; - console.error(`[${name}] exited (${reason})`); + logger.error("Process exited", { reason, code, signal }, name); void shutdown().then(() => process.exit(code ?? 1)); }; const handleSpawnError = (name: string, error: unknown) => { if (shuttingDown) return; - console.error(`[${name}] failed to start: ${String(error)}`); + logger.error("Process failed to start", { error: String(error) }, name); void shutdown().then(() => process.exit(1)); }; @@ -2613,8 +2861,12 @@ async function runStart(args: ParsedArgs) { username: opencodeUsername, password: opencodePassword, corsOrigins: corsOrigins.length ? corsOrigins : ["*"], + logger, + runId, + logFormat, }); children.push({ name: "opencode", child: opencodeChild }); + logger.info("Process spawned", { pid: opencodeChild.pid ?? 0 }, "opencode"); opencodeChild.on("exit", (code, signal) => handleExit("opencode", code, signal)); opencodeChild.on("error", (error) => handleSpawnError("opencode", error)); @@ -2628,7 +2880,9 @@ async function runStart(args: ParsedArgs) { headers: Object.keys(authHeaders).length ? authHeaders : undefined, }); + logger.info("Waiting for health", { url: opencodeBaseUrl }, "opencode"); await waitForOpencodeHealthy(opencodeClient); + logger.info("Healthy", { url: opencodeBaseUrl }, "opencode"); const openworkChild = await startOpenworkServer({ bin: openworkServerBinary.bin, @@ -2646,12 +2900,18 @@ async function runStart(args: ParsedArgs) { opencodeUsername, opencodePassword, owpenbotHealthPort, + logger, + runId, + logFormat, }); children.push({ name: "openwork-server", child: openworkChild }); + logger.info("Process spawned", { pid: openworkChild.pid ?? 0 }, "openwork-server"); openworkChild.on("exit", (code, signal) => handleExit("openwork-server", code, signal)); openworkChild.on("error", (error) => handleSpawnError("openwork-server", error)); + logger.info("Waiting for health", { url: openworkBaseUrl }, "openwork-server"); await waitForHealthy(openworkBaseUrl); + logger.info("Healthy", { url: openworkBaseUrl }, "openwork-server"); const openworkActualVersion = await verifyOpenworkServer({ baseUrl: openworkBaseUrl, @@ -2679,20 +2939,25 @@ async function runStart(args: ParsedArgs) { opencodeUsername, opencodePassword, owpenbotHealthPort, + logger, + runId, + logFormat, }); children.push({ name: "owpenbot", child: owpenbotChild }); + logger.info("Process spawned", { pid: owpenbotChild.pid ?? 0 }, "owpenbot"); owpenbotChild.on("exit", (code, signal) => { if (owpenbotRequired) { handleExit("owpenbot", code, signal); return; } const reason = code !== null ? `code ${code}` : signal ? `signal ${signal}` : "unknown"; - console.warn(`[owpenbot] exited (${reason}). Continuing without owpenbot.`); + logger.warn("Process exited, continuing without owpenbot", { reason, code, signal }, "owpenbot"); }); owpenbotChild.on("error", (error) => handleSpawnError("owpenbot", error)); } const payload = { + runId, workspace: resolvedWorkspace, approval: { mode: approvalMode, @@ -2760,8 +3025,20 @@ async function runStart(args: ParsedArgs) { if (outputJson) { console.log(JSON.stringify(payload, null, 2)); + } else if (logFormat === "json") { + logger.info( + "Ready", + { + workspace: payload.workspace, + opencode: payload.opencode, + openwork: payload.openwork, + owpenbot: payload.owpenbot, + }, + "openwrk", + ); } else { console.log("Openwrk running"); + console.log(`Run ID: ${runId}`); console.log(`Workspace: ${payload.workspace}`); console.log(`OpenCode: ${payload.opencode.baseUrl}`); console.log(`OpenCode connect URL: ${payload.opencode.connectUrl}`); @@ -2782,11 +3059,12 @@ async function runStart(args: ParsedArgs) { openworkToken, checkEvents, }); - if (!outputJson) { + logger.info("Checks ok", { checkEvents }, "openwrk"); + if (!outputJson && logFormat === "pretty") { console.log("Checks: ok"); } } catch (error) { - console.error(`Checks failed: ${String(error)}`); + logger.error("Checks failed", { error: String(error) }, "openwrk"); await shutdown(); process.exit(1); } @@ -2799,7 +3077,7 @@ async function runStart(args: ParsedArgs) { await new Promise(() => undefined); } catch (error) { await shutdown(); - console.error(error instanceof Error ? error.message : String(error)); + logger.error("Run failed", { error: error instanceof Error ? error.message : String(error) }, "openwrk"); process.exit(1); } } diff --git a/packages/server/src/cli.ts b/packages/server/src/cli.ts index a839ee94..1a5aefa7 100644 --- a/packages/server/src/cli.ts +++ b/packages/server/src/cli.ts @@ -1,7 +1,7 @@ #!/usr/bin/env bun import { parseCliArgs, printHelp, resolveServerConfig } from "./config.js"; -import { startServer } from "./server.js"; +import { createServerLogger, startServer } from "./server.js"; import pkg from "../package.json" with { type: "json" }; const args = parseCliArgs(process.argv.slice(2)); @@ -17,31 +17,32 @@ if (args.version) { } const config = await resolveServerConfig(args); +const logger = createServerLogger(config); const server = startServer(config); const url = `http://${config.host}:${server.port}`; -console.log(`OpenWork server listening on ${url}`); +logger.log("info", `OpenWork server listening on ${url}`); if (config.tokenSource === "generated") { - console.log(`Client token: ${config.token}`); + logger.log("info", `Client token: ${config.token}`); } if (config.hostTokenSource === "generated") { - console.log(`Host token: ${config.hostToken}`); + logger.log("info", `Host token: ${config.hostToken}`); } if (config.workspaces.length === 0) { - console.log("No workspaces configured. Add --workspace or update server.json."); + logger.log("info", "No workspaces configured. Add --workspace or update server.json."); } else { - console.log(`Workspaces: ${config.workspaces.length}`); + logger.log("info", `Workspaces: ${config.workspaces.length}`); } if (args.verbose) { - console.log(`Config path: ${config.configPath ?? "unknown"}`); - console.log(`Read-only: ${config.readOnly ? "true" : "false"}`); - console.log(`Approval: ${config.approval.mode} (${config.approval.timeoutMs}ms)`); - console.log(`CORS origins: ${config.corsOrigins.join(", ")}`); - console.log(`Authorized roots: ${config.authorizedRoots.join(", ")}`); - console.log(`Token source: ${config.tokenSource}`); - console.log(`Host token source: ${config.hostTokenSource}`); + logger.log("info", `Config path: ${config.configPath ?? "unknown"}`); + logger.log("info", `Read-only: ${config.readOnly ? "true" : "false"}`); + logger.log("info", `Approval: ${config.approval.mode} (${config.approval.timeoutMs}ms)`); + logger.log("info", `CORS origins: ${config.corsOrigins.join(", ")}`); + logger.log("info", `Authorized roots: ${config.authorizedRoots.join(", ")}`); + logger.log("info", `Token source: ${config.tokenSource}`); + logger.log("info", `Host token source: ${config.hostTokenSource}`); } diff --git a/packages/server/src/config.ts b/packages/server/src/config.ts index e418e1eb..a79e8fb4 100644 --- a/packages/server/src/config.ts +++ b/packages/server/src/config.ts @@ -1,6 +1,6 @@ import { homedir } from "node:os"; import { dirname, resolve } from "node:path"; -import type { ApprovalMode, ApprovalConfig, ServerConfig, WorkspaceConfig } from "./types.js"; +import type { ApprovalMode, ApprovalConfig, ServerConfig, WorkspaceConfig, LogFormat } from "./types.js"; import { buildWorkspaceInfos } from "./workspaces.js"; import { parseList, readJsonFile, shortId } from "./utils.js"; @@ -20,6 +20,8 @@ interface CliArgs { corsOrigins?: string[]; readOnly?: boolean; verbose?: boolean; + logFormat?: LogFormat; + logRequests?: boolean; version?: boolean; help?: boolean; } @@ -36,11 +38,31 @@ interface FileConfig { readOnly?: boolean; opencodeUsername?: string; opencodePassword?: string; + logFormat?: LogFormat; + logRequests?: boolean; } const DEFAULT_PORT = 8787; const DEFAULT_HOST = "127.0.0.1"; const DEFAULT_TIMEOUT_MS = 30000; +const DEFAULT_LOG_FORMAT: LogFormat = "pretty"; +const DEFAULT_LOG_REQUESTS = true; + +function normalizeLogFormat(value: string | undefined): LogFormat | undefined { + if (!value) return undefined; + const normalized = value.trim().toLowerCase(); + if (normalized === "json") return "json"; + if (normalized === "pretty" || normalized === "text" || normalized === "human") return "pretty"; + return undefined; +} + +function parseBoolean(value: string | undefined): boolean | undefined { + if (!value) return undefined; + const normalized = value.trim().toLowerCase(); + if (["true", "1", "yes", "on"].includes(normalized)) return true; + if (["false", "0", "no", "off"].includes(normalized)) return false; + return undefined; +} export function parseCliArgs(argv: string[]): CliArgs { const args: CliArgs = { workspaces: [] }; @@ -59,6 +81,19 @@ export function parseCliArgs(argv: string[]): CliArgs { args.verbose = true; continue; } + if (value === "--log-format") { + args.logFormat = argv[index + 1] as LogFormat | undefined; + index += 1; + continue; + } + if (value === "--log-requests") { + args.logRequests = true; + continue; + } + if (value === "--no-log-requests") { + args.logRequests = false; + continue; + } if (value === "--config") { args.configPath = argv[index + 1]; index += 1; @@ -155,6 +190,9 @@ export function printHelp(): void { " --workspace Workspace root (repeatable)", " --cors Comma-separated origins or *", " --read-only Disable writes", + " --log-format Log output format: pretty | json", + " --log-requests Log incoming requests (default: true)", + " --no-log-requests Disable request logging", " --verbose Print resolved config", " --version Show version", ].join("\n"); @@ -255,6 +293,16 @@ export async function resolveServerConfig(cli: CliArgs): Promise { : undefined; const readOnly = cli.readOnly ?? parsedReadOnly ?? fileConfig.readOnly ?? false; + const envLogFormat = process.env.OPENWORK_LOG_FORMAT; + const logFormat = + cli.logFormat ?? + normalizeLogFormat(envLogFormat) ?? + normalizeLogFormat(fileConfig.logFormat) ?? + DEFAULT_LOG_FORMAT; + + const envLogRequests = parseBoolean(process.env.OPENWORK_LOG_REQUESTS); + const logRequests = cli.logRequests ?? envLogRequests ?? fileConfig.logRequests ?? DEFAULT_LOG_REQUESTS; + const authorizedRoots = fileConfig.authorizedRoots?.length ? fileConfig.authorizedRoots.map((root) => resolve(configDir, root)) @@ -277,5 +325,7 @@ export async function resolveServerConfig(cli: CliArgs): Promise { startedAt: Date.now(), tokenSource, hostTokenSource, + logFormat, + logRequests, }; } diff --git a/packages/server/src/server.ts b/packages/server/src/server.ts index b1b10279..342785b3 100644 --- a/packages/server/src/server.ts +++ b/packages/server/src/server.ts @@ -1,5 +1,5 @@ import { readFile, writeFile, rm } from "node:fs/promises"; -import { homedir } from "node:os"; +import { homedir, hostname } from "node:os"; import { join, resolve, sep } from "node:path"; import type { ApprovalRequest, Capabilities, ServerConfig, WorkspaceInfo, Actor, ReloadReason, ReloadTrigger } from "./types.js"; import { ApprovalService } from "./approvals.js"; @@ -20,6 +20,91 @@ import pkg from "../package.json" with { type: "json" }; const SERVER_VERSION = pkg.version; +type LogLevel = "info" | "warn" | "error"; + +type LogAttributes = Record; + +type ServerLogger = { + log: (level: LogLevel, message: string, attributes?: LogAttributes) => void; +}; + +const LOG_LEVEL_NUMBERS: Record = { + info: 9, + warn: 13, + error: 17, +}; + +function toUnixNano(): string { + return (BigInt(Date.now()) * 1_000_000n).toString(); +} + +export function createServerLogger(config: ServerConfig): ServerLogger { + const runId = process.env.OPENWRK_RUN_ID ?? process.env.OPENWORK_RUN_ID ?? shortId(); + const host = hostname().trim(); + const resource: Record = { + "service.name": "openwork-server", + "service.version": SERVER_VERSION, + "service.instance.id": runId, + }; + if (host) { + resource["host.name"] = host; + } + const baseAttributes: LogAttributes = { + "run.id": runId, + "process.pid": process.pid, + }; + + const emit = (level: LogLevel, message: string, attributes?: LogAttributes) => { + const merged = { ...baseAttributes, ...(attributes ?? {}) }; + if (config.logFormat === "json") { + const record = { + timeUnixNano: toUnixNano(), + severityText: level.toUpperCase(), + severityNumber: LOG_LEVEL_NUMBERS[level], + body: message, + attributes: merged, + resource, + }; + process.stdout.write(`${JSON.stringify(record)}\n`); + return; + } + process.stdout.write(`${message}\n`); + }; + + return { log: emit }; +} + +function logRequest(input: { + logger: ServerLogger; + request: Request; + response: Response; + durationMs: number; + authMode: AuthMode; + proxyBaseUrl?: string; + error?: string; +}) { + const { logger, request, response, durationMs, authMode, proxyBaseUrl, error } = input; + const status = response.status; + const level: LogLevel = status >= 500 ? "error" : status >= 400 ? "warn" : "info"; + const url = new URL(request.url); + const method = request.method.toUpperCase(); + const message = `${method} ${url.pathname} ${status} ${durationMs}ms${proxyBaseUrl ? " (opencode)" : ""}`; + const attributes: LogAttributes = { + method, + path: url.pathname, + status, + durationMs, + auth: authMode, + }; + if (proxyBaseUrl) { + attributes["opencode.base_url"] = proxyBaseUrl; + } + if (error) { + attributes.error = error; + } + logger.log(level, message, attributes); +} + type AuthMode = "none" | "client" | "host"; interface Route { @@ -44,6 +129,7 @@ export function startServer(config: ServerConfig) { const approvals = new ApprovalService(config.approval); const reloadEvents = new ReloadEventStore(); const routes = createRoutes(config, approvals); + const logger = createServerLogger(config); const serverOptions: { hostname: string; @@ -54,28 +140,54 @@ export function startServer(config: ServerConfig) { port: config.port, fetch: async (request: Request) => { const url = new URL(request.url); + const startedAt = Date.now(); + let authMode: AuthMode = "none"; + let proxyBaseUrl: string | undefined; + let errorMessage: string | undefined; + + const finalize = (response: Response) => { + const wrapped = withCors(response, request, config); + if (config.logRequests) { + logRequest({ + logger, + request, + response: wrapped, + durationMs: Date.now() - startedAt, + authMode, + proxyBaseUrl, + error: errorMessage, + }); + } + return wrapped; + }; + if (request.method === "OPTIONS") { - return withCors(new Response(null, { status: 204 }), request, config); + return finalize(new Response(null, { status: 204 })); } if (url.pathname === "/opencode" || url.pathname.startsWith("/opencode/")) { + authMode = "client"; + proxyBaseUrl = config.workspaces[0]?.baseUrl?.trim() || undefined; try { requireClient(request, config); const response = await proxyOpencodeRequest({ request, url, config }); - return withCors(response, request, config); + return finalize(response); } catch (error) { const apiError = error instanceof ApiError ? error : new ApiError(500, "internal_error", "Unexpected server error"); - return withCors(jsonResponse(formatError(apiError), apiError.status), request, config); + errorMessage = apiError.message; + return finalize(jsonResponse(formatError(apiError), apiError.status)); } } const route = matchRoute(routes, request.method, url.pathname); if (!route) { - return withCors(jsonResponse({ code: "not_found", message: "Not found" }, 404), request, config); + errorMessage = "not_found"; + return finalize(jsonResponse({ code: "not_found", message: "Not found" }, 404)); } + authMode = route.auth; try { const actor = route.auth === "host" ? requireHost(request, config) : route.auth === "client" ? requireClient(request, config) : undefined; const response = await route.handler({ @@ -87,12 +199,13 @@ export function startServer(config: ServerConfig) { reloadEvents, actor, }); - return withCors(response, request, config); + return finalize(response); } catch (error) { const apiError = error instanceof ApiError ? error : new ApiError(500, "internal_error", "Unexpected server error"); - return withCors(jsonResponse(formatError(apiError), apiError.status), request, config); + errorMessage = apiError.message; + return finalize(jsonResponse(formatError(apiError), apiError.status)); } }, }; diff --git a/packages/server/src/types.ts b/packages/server/src/types.ts index df791d29..49de8c84 100644 --- a/packages/server/src/types.ts +++ b/packages/server/src/types.ts @@ -2,6 +2,8 @@ export type WorkspaceType = "local" | "remote"; export type ApprovalMode = "manual" | "auto"; +export type LogFormat = "pretty" | "json"; + export interface WorkspaceConfig { path: string; name?: string; @@ -48,6 +50,8 @@ export interface ServerConfig { startedAt: number; tokenSource: "cli" | "env" | "file" | "generated"; hostTokenSource: "cli" | "env" | "file" | "generated"; + logFormat: LogFormat; + logRequests: boolean; } export interface Capabilities {