diff --git a/config.template.jsonc b/config.template.jsonc index 23ed2515d3..c1b7e49e63 100644 --- a/config.template.jsonc +++ b/config.template.jsonc @@ -16,6 +16,12 @@ // `dev` opens a browser on boot, skips blocked-email checks, and runs the // dev-time webpack watcher; `prod` serves pre-built bundles. "env": "dev", + // Console output format. `json` replaces the global console so every call + // emits one structured JSON line (level, timestamp, msg, and the active + // request's trace id) — one event per call, so a line-oriented log + // collector can't split stack traces across events and level filtering + // works. Unset (the default) leaves console output human-readable. + "log_format": "text", "version": "0.0.0", // Stable identity for this server node — used by pager alerts and // graceful-shutdown coordination. diff --git a/src/backend/index.ts b/src/backend/index.ts index 9d5f66519c..b2a8d55cf0 100644 --- a/src/backend/index.ts +++ b/src/backend/index.ts @@ -19,6 +19,7 @@ import { existsSync, readFileSync } from 'node:fs'; import path from 'node:path'; +import { isSpanContextValid, trace } from '@opentelemetry/api'; import { puterClients } from './clients'; import { puterControllers } from './controllers'; import { puterDrivers } from './drivers'; @@ -26,6 +27,7 @@ import { PuterServer } from './server'; import { puterServices } from './services'; import { puterStores } from './stores'; import type { IConfig } from './types'; +import { installJsonConsole } from './util/jsonConsole.js'; // Config resolution order: // 1. `process.env.PUTER_CONFIG_PATH` — absolute path to a config file. Used @@ -167,6 +169,23 @@ const loadConfig = (): IConfig => { // if called directly, start the server if (require.main === module) { const config = loadConfig(); + + // Structured logging: when `log_format: "json"`, replace the global console + // so each call emits one JSON line (level, timestamp, msg, and the active + // trace id) — one event per call, so a line-oriented log collector can't + // split stack traces across events. Installed here rather than in the OTel + // preload so it applies even when telemetry is disabled; the trace id is + // simply absent when no span is active. + if (config.log_format === 'json') { + installJsonConsole({ + getTraceContext: () => { + const ctx = trace.getActiveSpan()?.spanContext(); + if (!ctx || !isSpanContextValid(ctx)) return undefined; + return { traceId: ctx.traceId, spanId: ctx.spanId }; + }, + }); + } + const server = new PuterServer( config, puterClients, diff --git a/src/backend/types.ts b/src/backend/types.ts index a8315b4990..cd6f536df7 100644 --- a/src/backend/types.ts +++ b/src/backend/types.ts @@ -452,6 +452,14 @@ interface IConfigOptional { env: 'dev' | 'prod'; /** Free-form name of the config profile (e.g. `oss-default`). Surfaced in logs. */ config_name: string; + /** + * Console output format. `json` replaces the global console so every call + * emits one structured JSON line (`level`, `timestamp`, `msg`, and the + * active `traceId`) — one event per call, so a line-oriented log collector + * can't split stack traces across events, and level filtering works. `text` + * (the default) leaves console output human-readable for local/dev. + */ + log_format: 'json' | 'text'; /** Server version. Falls back to `npm_package_version`. */ version: string; /** Stable identity for this server node. Enables pager alerts + graceful shutdown delay. */ diff --git a/src/backend/util/jsonConsole.test.ts b/src/backend/util/jsonConsole.test.ts new file mode 100644 index 0000000000..97e406531b --- /dev/null +++ b/src/backend/util/jsonConsole.test.ts @@ -0,0 +1,164 @@ +/** + * Copyright (C) 2024-present Puter Technologies Inc. + * + * This file is part of Puter. + * + * Puter is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published + * by the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +import { afterEach, describe, expect, it, vi } from 'vitest'; +import { installJsonConsole } from './jsonConsole.js'; + +/** + * Capture what the patched console writes to stdout/stderr. Returns the raw + * chunks plus helpers to parse them, then uninstall() restores everything. + */ +const withInstalledConsole = ( + options?: Parameters[0], +) => { + const out: string[] = []; + const err: string[] = []; + const stdout = vi + .spyOn(process.stdout, 'write') + .mockImplementation((chunk: unknown) => { + out.push(String(chunk)); + return true; + }); + const stderr = vi + .spyOn(process.stderr, 'write') + .mockImplementation((chunk: unknown) => { + err.push(String(chunk)); + return true; + }); + const uninstall = installJsonConsole(options); + return { + out, + err, + uninstall: () => { + uninstall(); + stdout.mockRestore(); + stderr.mockRestore(); + }, + }; +}; + +describe('installJsonConsole', () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + it('emits one JSON line per call with level, timestamp and msg', () => { + const { out, uninstall } = withInstalledConsole(); + try { + console.log('hello world'); + } finally { + uninstall(); + } + + expect(out).toHaveLength(1); + expect(out[0].endsWith('\n')).toBe(true); + const entry = JSON.parse(out[0]); + expect(entry.level).toBe('info'); + expect(entry.msg).toBe('hello world'); + expect(() => new Date(entry.timestamp).toISOString()).not.toThrow(); + expect(entry.timestamp).toBe(new Date(entry.timestamp).toISOString()); + }); + + it('maps each console method to the expected level and stream', () => { + const { out, err, uninstall } = withInstalledConsole(); + try { + console.info('i'); + console.debug('d'); + console.warn('w'); + console.error('e'); + } finally { + uninstall(); + } + + expect(out.map((l) => JSON.parse(l).level)).toEqual(['info', 'debug']); + expect(err.map((l) => JSON.parse(l).level)).toEqual(['warn', 'error']); + }); + + it('formats non-string args like console does (objects preserved)', () => { + const { out, uninstall } = withInstalledConsole(); + try { + console.log('user', { id: 5, roles: ['a'] }, [1, 2]); + } finally { + uninstall(); + } + + const entry = JSON.parse(out[0]); + expect(entry.msg).toBe("user { id: 5, roles: [ 'a' ] } [ 1, 2 ]"); + }); + + it('collapses a multi-line stack trace into a single log event', () => { + const { err, uninstall } = withInstalledConsole(); + try { + console.error(new Error('boom')); + } finally { + uninstall(); + } + + // Exactly one write, one trailing newline, no interior raw newlines + // (the stack lives inside the JSON-escaped `msg` string). + expect(err).toHaveLength(1); + expect(err[0].match(/\n/g)).toHaveLength(1); + const entry = JSON.parse(err[0]); + expect(entry.level).toBe('error'); + expect(entry.msg).toContain('Error: boom'); + expect(entry.msg).toContain('\n at '); // stack frames survive in msg + }); + + it('attaches traceId/spanId only when a span is active', () => { + let ctx: { traceId: string; spanId?: string } | undefined; + const { out, uninstall } = withInstalledConsole({ + getTraceContext: () => ctx, + }); + try { + console.log('no span'); + ctx = { traceId: 'abc123', spanId: 'def456' }; + console.log('with span'); + } finally { + uninstall(); + } + + const first = JSON.parse(out[0]); + expect(first).not.toHaveProperty('traceId'); + const second = JSON.parse(out[1]); + expect(second.traceId).toBe('abc123'); + expect(second.spanId).toBe('def456'); + }); + + it('restores the original console methods on uninstall', () => { + const before = console.log; + const { uninstall } = withInstalledConsole(); + expect(console.log).not.toBe(before); + uninstall(); + expect(console.log).toBe(before); + }); + + it('is idempotent — a second install is a no-op', () => { + const { out, uninstall } = withInstalledConsole(); + const second = installJsonConsole(); + try { + console.log('once'); + } finally { + second(); + uninstall(); + } + // Still a single JSON line, not double-patched. + expect(out).toHaveLength(1); + expect(JSON.parse(out[0]).msg).toBe('once'); + }); +}); diff --git a/src/backend/util/jsonConsole.ts b/src/backend/util/jsonConsole.ts new file mode 100644 index 0000000000..e247fb44b6 --- /dev/null +++ b/src/backend/util/jsonConsole.ts @@ -0,0 +1,116 @@ +/** + * Copyright (C) 2024-present Puter Technologies Inc. + * + * This file is part of Puter. + * + * Puter is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published + * by the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +import { format } from 'node:util'; + +/** + * Console severity methods we replace, mapped to the `level` value emitted for + * each. `log` collapses to `info` so downstream `level = "info"` / `"error"` + * filters behave conventionally. + */ +const METHOD_LEVELS = { + log: 'info', + info: 'info', + warn: 'warn', + error: 'error', + debug: 'debug', +} as const; + +type ConsoleMethod = keyof typeof METHOD_LEVELS; + +/** Identifiers for the currently-active trace, if any. */ +export interface TraceContext { + traceId: string; + spanId?: string; +} + +export interface JsonConsoleOptions { + /** + * Resolves the active trace context at log time, or `undefined` when no + * recording span is active. Kept as a callback so this module carries no + * telemetry dependency and stays trivially unit-testable. + */ + getTraceContext?: () => TraceContext | undefined; +} + +// Guard against double-installation across duplicate module instances. +const INSTALLED_FLAG = '__puterJsonConsoleInstalled'; + +/** + * Replace the global console severity methods so every call emits exactly one + * line of JSON: `{ level, timestamp, msg, traceId?, spanId? }`. `msg` is + * `util.format`ed from the call args — byte-for-byte what console would have + * printed — so multi-line values (stack traces, inspected objects) become a + * single log event instead of being split across many by a line-oriented log + * collector. + * + * Returns a function that restores the original console methods. + */ +export const installJsonConsole = ( + options: JsonConsoleOptions = {}, +): (() => void) => { + const globals = globalThis as Record; + if (globals[INSTALLED_FLAG]) return () => {}; + + const { getTraceContext } = options; + const originals = {} as Record void>; + + for (const method of Object.keys(METHOD_LEVELS) as ConsoleMethod[]) { + // Keep the exact reference so uninstall() restores it identically. + const original = console[method] as (...args: unknown[]) => void; + originals[method] = original; + + const level = METHOD_LEVELS[method]; + // Match console's stream routing so stderr keeps carrying warnings and + // errors even in JSON mode. + const stream = + method === 'warn' || method === 'error' + ? process.stderr + : process.stdout; + + console[method] = (...args: unknown[]): void => { + try { + const entry: Record = { + level, + timestamp: new Date().toISOString(), + msg: format(...args), + }; + const trace = getTraceContext?.(); + if (trace?.traceId) { + entry.traceId = trace.traceId; + if (trace.spanId) entry.spanId = trace.spanId; + } + stream.write(`${JSON.stringify(entry)}\n`); + } catch { + // Logging must never take down the process — fall back to the + // untouched console method if formatting/serialization throws. + original.apply(console, args); + } + }; + } + + globals[INSTALLED_FLAG] = true; + + return () => { + for (const method of Object.keys(originals) as ConsoleMethod[]) { + console[method] = originals[method]; + } + delete globals[INSTALLED_FLAG]; + }; +};