From 04fc86bf3123d71f787255d9eee45ef921b9eba9 Mon Sep 17 00:00:00 2001 From: Neal Shah Date: Mon, 13 Jul 2026 01:12:02 -0400 Subject: [PATCH 1/2] add support for ndjson logging --- config.template.jsonc | 6 + src/backend/telemetry.ts | 54 +++++++++ src/backend/types.ts | 8 ++ src/backend/util/jsonConsole.test.ts | 164 +++++++++++++++++++++++++++ src/backend/util/jsonConsole.ts | 116 +++++++++++++++++++ 5 files changed, 348 insertions(+) create mode 100644 src/backend/util/jsonConsole.test.ts create mode 100644 src/backend/util/jsonConsole.ts 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/telemetry.ts b/src/backend/telemetry.ts index d8aed4257d..3b15c8ce1b 100644 --- a/src/backend/telemetry.ts +++ b/src/backend/telemetry.ts @@ -17,6 +17,7 @@ * along with this program. If not, see . */ +import { isSpanContextValid, trace } from '@opentelemetry/api'; import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node'; import { OTLPMetricExporter } from '@opentelemetry/exporter-metrics-otlp-grpc'; import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-grpc'; @@ -32,6 +33,59 @@ import { ATTR_SERVICE_VERSION, } from '@opentelemetry/semantic-conventions'; +import { existsSync, readFileSync } from 'node:fs'; +import path from 'node:path'; +import { installJsonConsole } from './util/jsonConsole.js'; + +/** + * Resolve `log_format` with the SAME precedence as the server's `loadConfig` + * (index.ts): defaults from `config.default.json`, overlaid by a single + * override file — `PUTER_CONFIG_PATH` if it exists, else `/config.json`. + * This preload runs before the backend loads config, so it must stay in lockstep + * with that resolution or it'd act on a value the server never sees. + */ +const configLogFormat = (): unknown => { + const pkgRoot = path.resolve(__dirname, '../../..'); + const readJson = (file: string): Record => { + try { + return JSON.parse(readFileSync(file, 'utf8')); + } catch { + // A missing/invalid file is treated as no override; the server's + // loadConfig surfaces a real parse error moments later. + return {}; + } + }; + + const defaultPath = path.join(pkgRoot, 'config.default.json'); + const runtimePath = path.join(pkgRoot, 'config.json'); + const envPath = process.env.PUTER_CONFIG_PATH; + + const defaults = existsSync(defaultPath) ? readJson(defaultPath) : {}; + const overridePath = + envPath && existsSync(envPath) + ? envPath + : existsSync(runtimePath) + ? runtimePath + : null; + const override = overridePath ? readJson(overridePath) : {}; + + // deepMerge over a scalar key == override wins when it sets the key. + return 'log_format' in override ? override.log_format : defaults.log_format; +}; + +// When config sets `log_format: "json"`, replace the global console so every +// call emits one JSON line tagged with the active trace — one event per call, +// filterable by level. Any other value (the default) leaves console untouched. +if (configLogFormat() === 'json') { + installJsonConsole({ + getTraceContext: () => { + const ctx = trace.getActiveSpan()?.spanContext(); + if (!ctx || !isSpanContextValid(ctx)) return undefined; + return { traceId: ctx.traceId, spanId: ctx.spanId }; + }, + }); +} + const endpoint = process.env.OTEL_EXPORTER_OTLP_ENDPOINT ?? 'http://localhost:4317'; const sampleRatio = Number(process.env.OTEL_TRACE_SAMPLE_RATIO ?? 0.05); 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]; + }; +}; From 94b1fafd96e2cd3c0b45c91a1ddd46182fd13c07 Mon Sep 17 00:00:00 2001 From: Neal Shah Date: Mon, 13 Jul 2026 02:08:26 -0400 Subject: [PATCH 2/2] move install location --- src/backend/index.ts | 19 ++++++++++++++ src/backend/telemetry.ts | 54 ---------------------------------------- 2 files changed, 19 insertions(+), 54 deletions(-) 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/telemetry.ts b/src/backend/telemetry.ts index 3b15c8ce1b..d8aed4257d 100644 --- a/src/backend/telemetry.ts +++ b/src/backend/telemetry.ts @@ -17,7 +17,6 @@ * along with this program. If not, see . */ -import { isSpanContextValid, trace } from '@opentelemetry/api'; import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node'; import { OTLPMetricExporter } from '@opentelemetry/exporter-metrics-otlp-grpc'; import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-grpc'; @@ -33,59 +32,6 @@ import { ATTR_SERVICE_VERSION, } from '@opentelemetry/semantic-conventions'; -import { existsSync, readFileSync } from 'node:fs'; -import path from 'node:path'; -import { installJsonConsole } from './util/jsonConsole.js'; - -/** - * Resolve `log_format` with the SAME precedence as the server's `loadConfig` - * (index.ts): defaults from `config.default.json`, overlaid by a single - * override file — `PUTER_CONFIG_PATH` if it exists, else `/config.json`. - * This preload runs before the backend loads config, so it must stay in lockstep - * with that resolution or it'd act on a value the server never sees. - */ -const configLogFormat = (): unknown => { - const pkgRoot = path.resolve(__dirname, '../../..'); - const readJson = (file: string): Record => { - try { - return JSON.parse(readFileSync(file, 'utf8')); - } catch { - // A missing/invalid file is treated as no override; the server's - // loadConfig surfaces a real parse error moments later. - return {}; - } - }; - - const defaultPath = path.join(pkgRoot, 'config.default.json'); - const runtimePath = path.join(pkgRoot, 'config.json'); - const envPath = process.env.PUTER_CONFIG_PATH; - - const defaults = existsSync(defaultPath) ? readJson(defaultPath) : {}; - const overridePath = - envPath && existsSync(envPath) - ? envPath - : existsSync(runtimePath) - ? runtimePath - : null; - const override = overridePath ? readJson(overridePath) : {}; - - // deepMerge over a scalar key == override wins when it sets the key. - return 'log_format' in override ? override.log_format : defaults.log_format; -}; - -// When config sets `log_format: "json"`, replace the global console so every -// call emits one JSON line tagged with the active trace — one event per call, -// filterable by level. Any other value (the default) leaves console untouched. -if (configLogFormat() === 'json') { - installJsonConsole({ - getTraceContext: () => { - const ctx = trace.getActiveSpan()?.spanContext(); - if (!ctx || !isSpanContextValid(ctx)) return undefined; - return { traceId: ctx.traceId, spanId: ctx.spanId }; - }, - }); -} - const endpoint = process.env.OTEL_EXPORTER_OTLP_ENDPOINT ?? 'http://localhost:4317'; const sampleRatio = Number(process.env.OTEL_TRACE_SAMPLE_RATIO ?? 0.05);