diff --git a/server/index.ts b/server/index.ts index 709c53d37..afa17d232 100644 --- a/server/index.ts +++ b/server/index.ts @@ -16,6 +16,10 @@ import { getStartupConfigurationEntries, } from "./startup-access"; import { apiRateLimitKey, shouldSkipApiRateLimit } from "./rate-limit-policy"; +import { + safeErrorLogMetadata, + safeErrorStackFrames, +} from "./services/safe-error-log-metadata"; const __dirname = path.dirname(fileURLToPath(import.meta.url)); @@ -152,27 +156,11 @@ app.use( app.use((req, res, next) => { const start = Date.now(); const reqPath = req.path; - let capturedJsonResponse: Record | undefined = undefined; - - const originalResJson = res.json; - res.json = function (bodyJson, ...args) { - capturedJsonResponse = bodyJson; - return originalResJson.apply(res, [bodyJson, ...args]); - }; res.on("finish", () => { const duration = Date.now() - start; if (reqPath.startsWith("/api") && reqPath !== "/api/health") { - let logLine = `${req.method} ${reqPath} ${res.statusCode} in ${duration}ms`; - if (capturedJsonResponse) { - logLine += ` :: ${JSON.stringify(capturedJsonResponse)}`; - } - - if (logLine.length > 80) { - logLine = logLine.slice(0, 79) + "…"; - } - - log(logLine); + log(`${req.method} ${reqPath} ${res.statusCode} in ${duration}ms`); } }); @@ -180,12 +168,17 @@ app.use((req, res, next) => { }); // Global error handlers to prevent server crashes -process.on("unhandledRejection", (reason, promise) => { - console.error(`[ERROR] Unhandled Promise Rejection:`, promise, reason); +function safeStackSuffix(error: unknown): string { + const stackFrames = safeErrorStackFrames(error); + return stackFrames ? "\n" + stackFrames : ""; +} + +process.on("unhandledRejection", (reason) => { + console.error("[ERROR] Unhandled Promise Rejection (" + safeErrorLogMetadata(reason) + ")" + safeStackSuffix(reason)); }); process.on("uncaughtException", (error) => { - console.error(`[ERROR] Uncaught Exception:`, error); + console.error("[ERROR] Uncaught Exception (" + safeErrorLogMetadata(error) + ")" + safeStackSuffix(error)); // In development, keep running; in production may want to restart if (config.serverMode === "docker") { console.error("Shutting down due to uncaught exception"); @@ -211,10 +204,7 @@ let cleanupTimer: NodeJS.Timeout | null = null; // Logging für Debugging (Server-seitig) if (status >= 500) { - console.error( - `[ERROR] ${status}: ${err.message}`, - isProduction ? "" : err.stack, - ); + console.error(`[ERROR] ${status} (` + safeErrorLogMetadata(err) + ")" + safeStackSuffix(err)); } res.status(status).json({ message }); diff --git a/server/routes/compiler.routes.ts b/server/routes/compiler.routes.ts index b7ca96b23..36a8aa258 100644 --- a/server/routes/compiler.routes.ts +++ b/server/routes/compiler.routes.ts @@ -10,6 +10,7 @@ import type { RequestIdentity } from "../security/access-control"; import type { RateLimitResult } from "../services/rate-limiter"; import { operationError, SYSTEM_BUSY_MESSAGE } from "@shared/operation-errors"; import { CompileCapacityError } from "../services/compilation-worker-pool"; +import { safeErrorLogMetadata } from "../services/safe-error-log-metadata"; type CompilerHeader = { name: string; content: string }; @@ -208,7 +209,7 @@ export function registerCompilerRoutes(app: Express, deps: CompilerDeps) { return res.status(503).json({ error: operationError("SYSTEM_BUSY", SYSTEM_BUSY_MESSAGE, retryAfter) }); } recordCompileErrorIfNeeded(compiler, compileStartTime, error); - logger.error(`[Compiler Route] Error during /api/compile: ${error instanceof Error ? error.message : String(error)}`); + logger.error(`[Compiler Route] Error during /api/compile (${safeErrorLogMetadata(error)})`); res.status(500).json({ error: "Compilation failed" }); } }); diff --git a/server/routes/simulation.ws.ts b/server/routes/simulation.ws.ts index a881075fc..686ac7814 100644 --- a/server/routes/simulation.ws.ts +++ b/server/routes/simulation.ws.ts @@ -31,6 +31,7 @@ import { import { operationError, SYSTEM_BUSY_MESSAGE } from "@shared/operation-errors"; import { config } from "../config"; import { InboundMessageLimiter } from "./simulation/ws-inbound-limiter"; +import { safeErrorLogMetadata } from "../services/safe-error-log-metadata"; function sendStartError( ws: WebSocket, @@ -252,7 +253,7 @@ export function registerSimulationWebSocket( }; const onError = (err: string) => { - logger.warn(`[Client WS][ERR]: ${err}`); + logger.warn(`[Client WS][ERR] diagnostic received (${Buffer.byteLength(err)} bytes)`); outputBuffer.flushSerialOutputBuffer(ws); sendMessageToClient(ws, { type: WSMessageType.SERIAL_OUTPUT, @@ -323,7 +324,7 @@ export function registerSimulationWebSocket( ); }); } - logger.error(`[Client Compile Error]: ${compileErr}`); + logger.error(`[Client Compile Error] diagnostic received (${Buffer.byteLength(compileErr)} bytes)`); }; const onCompileSuccess = () => { @@ -644,7 +645,7 @@ export function registerSimulationWebSocket( }); if (!processReady) return; } catch (error) { - logger.error(`[Simulation] runSketch failed: ${error}`); + logger.error(`[Simulation] runSketch failed (${safeErrorLogMetadata(error)})`); await sessionManager.safeReleaseRunner( clientState, "runSketch-error", diff --git a/server/services/arduino-output-parser.ts b/server/services/arduino-output-parser.ts index 14050fea2..f53f3a011 100644 --- a/server/services/arduino-output-parser.ts +++ b/server/services/arduino-output-parser.ts @@ -150,7 +150,7 @@ export class ArduinoOutputParser { /^[A-Za-z0-9+/=:]+\]\]$/.test(line) || // timestamp:base64 tail + ]] /^\d+:[A-Za-z0-9+/=]+/.test(line) // timestamp:base64 (no brackets) ) { - logger.debug(`Ignoring protocol fragment: ${line.slice(0, 80)}...`); + logger.debug("Ignoring partial simulator protocol fragment"); return { type: "ignored" }; } diff --git a/server/services/compilation-worker-pool.ts b/server/services/compilation-worker-pool.ts index c7875001b..9f59f9560 100644 --- a/server/services/compilation-worker-pool.ts +++ b/server/services/compilation-worker-pool.ts @@ -204,7 +204,7 @@ export class CompilationWorkerPool { worker.on("error", (err) => { if (!isCurrent()) return; - this.logger.error(`[Worker ${workerId}] Error: ${err.message}`); + this.logger.error(`[Worker ${workerId}] Error (${err.name})`); this.handleWorkerFailure(workerId, err); }); diff --git a/server/services/compiler/cli-runner.ts b/server/services/compiler/cli-runner.ts index 9da2d4c42..19e13cc5f 100644 --- a/server/services/compiler/cli-runner.ts +++ b/server/services/compiler/cli-runner.ts @@ -112,7 +112,11 @@ export async function compileWithArduinoCli( } catch (error) { const errorText = error instanceof Error ? error.message : String(error); const errorMessage = withPathHint(`Failed to execute arduino-cli: ${errorText}.`, error); - logger.error(errorMessage); + const errorType = error instanceof Error ? error.name : typeof error; + const errorCode = error && typeof error === "object" && "code" in error && typeof error.code === "string" + ? `, ${error.code}` + : ""; + logger.error(`Failed to execute arduino-cli (${errorType}${errorCode}, ${Buffer.byteLength(errorMessage)} diagnostic bytes)`); return { success: false, output: "", diff --git a/server/services/local-compiler.ts b/server/services/local-compiler.ts index 3822baf73..8e3f16d2a 100644 --- a/server/services/local-compiler.ts +++ b/server/services/local-compiler.ts @@ -144,7 +144,7 @@ export class LocalCompiler { break; } if (attempt < 2) { - this.logger.warn(`Compilation attempt ${attempt} failed, retrying... (${lastError.message})`); + this.logger.warn(`Compilation attempt ${attempt} failed (${lastError.name}); retrying`); await new Promise(r => setTimeout(r, 500)); } } @@ -198,8 +198,7 @@ export class LocalCompiler { if (result.error || result.code !== 0) { const cleanedError = this.cleanCompilerErrors(result.stderr || ""); - const errorMsg = `Compiler error (Code ${result.code}, attempt ${attempt}): ${cleanedError}`; - this.logger.error(errorMsg); + this.logger.error(`Compiler failed (code ${result.code}, attempt ${attempt}, ${Buffer.byteLength(cleanedError)} diagnostic bytes)`); throw new CompilerError(cleanedError); } diff --git a/server/services/process-controller.ts b/server/services/process-controller.ts index 979bbbedf..4bd172b8b 100644 --- a/server/services/process-controller.ts +++ b/server/services/process-controller.ts @@ -124,7 +124,7 @@ export class ProcessController implements IProcessController { if (process.env.NODE_ENV === "test") { // convert low-level wrapper events into buffered debug logs try { - logger.debug(`wrapper stderr handler invoked with: ${d.toString()}`); + logger.debug(`wrapper stderr handler received ${d.length} bytes`); } catch {} } this.stderrListeners.forEach((cb) => cb(d)); diff --git a/server/services/process-executor.ts b/server/services/process-executor.ts index 44d50f7ba..c267b7e62 100644 --- a/server/services/process-executor.ts +++ b/server/services/process-executor.ts @@ -210,8 +210,8 @@ export class ProcessExecutor { result.error = new Error(`Process timeout after ${timeout}ms`); this.logger.warn(`${command} timed out: ${result.error.message}`); } else if (code !== 0) { - result.error = new Error(`${command} exit code ${code}: ${stderr}`); - this.logger.warn(`${command} failed: ${result.error.message}`); + result.error = new Error(`${command} exit code ${code}`); + this.logger.warn(`${command} failed with exit code ${code} (${Buffer.byteLength(stderr)} stderr bytes)`); } resolve(result); @@ -223,7 +223,8 @@ export class ProcessExecutor { this.activeTimeout = null; } this.activeProcess = null; - this.logger.error(`${command} error: ${err.message}`); + const errorCode = "code" in err && typeof err.code === "string" ? `, ${err.code}` : ""; + this.logger.error(`${command} process error (${err.name}${errorCode})`); resolve({ code: -1, error: err, diff --git a/server/services/safe-error-log-metadata.ts b/server/services/safe-error-log-metadata.ts new file mode 100644 index 000000000..6343c00a2 --- /dev/null +++ b/server/services/safe-error-log-metadata.ts @@ -0,0 +1,19 @@ +export function safeErrorLogMetadata(error: unknown): string { + const errorType = error instanceof Error ? error.name : typeof error; + let messageBytes = 0; + if (error instanceof Error) { + messageBytes = Buffer.byteLength(error.message); + } else if (typeof error === "string") { + messageBytes = Buffer.byteLength(error); + } + const errorCode = error instanceof Error && "code" in error && typeof error.code === "string" + ? " code=" + error.code + : ""; + + return errorType + errorCode + ", " + messageBytes + " diagnostic bytes"; +} + +export function safeErrorStackFrames(error: unknown): string { + if (!(error instanceof Error) || !error.stack) return ""; + return error.stack.split("\n").slice(1, 6).join("\n"); +} diff --git a/server/services/sandbox/execution-manager.ts b/server/services/sandbox/execution-manager.ts index bb1f83590..be4bf22ec 100644 --- a/server/services/sandbox/execution-manager.ts +++ b/server/services/sandbox/execution-manager.ts @@ -317,7 +317,8 @@ export class ExecutionManager { return; } const errorMessage = err instanceof Error ? err.message : String(err); - this.logger.error(`Kompilierfehler oder Timeout: ${errorMessage}`); + const errorType = err instanceof Error ? err.name : typeof err; + this.logger.error(`Kompilierfehler oder Timeout (${errorType}, ${Buffer.byteLength(errorMessage)} diagnostic bytes)`); options.onCompileError?.(errorMessage); options.onExit?.(-1); state.processController.destroySockets(); diff --git a/server/services/sandbox/stream-handler.ts b/server/services/sandbox/stream-handler.ts index 2b7c5b324..8a4eef5eb 100644 --- a/server/services/sandbox/stream-handler.ts +++ b/server/services/sandbox/stream-handler.ts @@ -120,7 +120,7 @@ export class StreamHandler { case "text": if (callbacks.onError) { - this.logger.warn(`[STDERR]: ${parsed.line}`); + this.logger.warn(`[STDERR] diagnostic received (${Buffer.byteLength(parsed.line)} bytes)`); callbacks.onError(parsed.line); } break; diff --git a/server/services/workers/compile-worker.ts b/server/services/workers/compile-worker.ts index aeccc251b..e90837112 100644 --- a/server/services/workers/compile-worker.ts +++ b/server/services/workers/compile-worker.ts @@ -14,6 +14,7 @@ import { parentPort, workerData } from "node:worker_threads"; import { Logger } from "../../../shared/logger.ts"; +import { safeErrorLogMetadata } from "../safe-error-log-metadata.ts"; import { getFastTmpBaseDir } from "../../../shared/utils/temp-paths.ts"; import { type CompileRequestPayload, @@ -271,8 +272,7 @@ async function processCompileRequest(task: CompileRequestPayload) { } } catch (err) { - const errorMsg = err instanceof Error ? err.message : String(err); - logger.error(`[Worker] Compilation failed: ${errorMsg}`); + logger.error(`[Worker] Compilation failed (${safeErrorLogMetadata(err)})`); throw err; } } diff --git a/shared/logger.ts b/shared/logger.ts index 5bda62621..80899be4f 100644 --- a/shared/logger.ts +++ b/shared/logger.ts @@ -237,11 +237,12 @@ export function initializeGlobalErrorHandlers(): void { process.on("uncaughtException", (error: Error) => { // note: processError variable removed – we no longer track it separately - flushDebugOnFailure(`Uncaught Exception: ${error.message}`); + flushDebugOnFailure(`Uncaught Exception (${error.name})`); }); process.on("unhandledRejection", (reason: unknown) => { - flushDebugOnFailure(`Unhandled Rejection: ${String(reason)}`); + const reasonType = reason instanceof Error ? reason.name : typeof reason; + flushDebugOnFailure(`Unhandled Rejection (${reasonType})`); }); } @@ -256,5 +257,3 @@ export function markTestAsFailed(testName?: string): void { export function setLogLevel(level: LogLevel): void { globalLogLevel = level; } - - diff --git a/tests/server/dev-entrypoint.test.ts b/tests/server/dev-entrypoint.test.ts index 3de4bf394..0e77e760d 100644 --- a/tests/server/dev-entrypoint.test.ts +++ b/tests/server/dev-entrypoint.test.ts @@ -191,4 +191,31 @@ describe("local development entrypoint", () => { expect(output()).toContain("[Shutdown] Received SIGTERM"); expect(child.exitCode).toBe(0); }, 20_000); + + it("does not log sketch source included in a REST response", async () => { + const port = await reservePort(); + const child = spawnLocalDevelopment(createLocalServerEnv(port)); + const output = collectOutput(child); + const marker = "F01_REST_SOURCE_SENTINEL_2c0f6a"; + const markerPrefix = "F01_REST_SOURCE"; + try { + await waitForReadiness(child, port, output); + const response = await fetch(`http://127.0.0.1:${port}/api/sketches`, { + method: "POST", + headers: { "Content-Type": "application/json" }, + body: JSON.stringify({ name: "", content: marker }), + }); + + expect(response.status).toBe(201); + expect(await response.json()).toMatchObject({ content: marker }); + const deadline = Date.now() + 1_000; + while (!output().includes("POST /api/sketches 201") && Date.now() < deadline) { + await new Promise((resolve) => setTimeout(resolve, 10)); + } + expect(output()).toContain("POST /api/sketches 201"); + expect(output()).not.toContain(markerPrefix); + } finally { + await stopProcess(child); + } + }, 20_000); }); diff --git a/tests/server/routes/compiler.routes.test.ts b/tests/server/routes/compiler.routes.test.ts index 088f32255..f28b12713 100644 --- a/tests/server/routes/compiler.routes.test.ts +++ b/tests/server/routes/compiler.routes.test.ts @@ -341,10 +341,12 @@ describe("compiler.routes - /api/compile", () => { }); it("handles compiler exceptions", async () => { - deps.compiler.compile.mockRejectedValueOnce(new Error("Compiler crashed")); + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; + deps.compiler.compile.mockRejectedValueOnce(new Error(diagnostic)); const res = await post(baseUrl, "/api/compile", { code: "crash_code" }); expect(res.status).toBe(500); expect(res.body.error).toBe("Compilation failed"); + expect(deps.logger.error.mock.calls.flat().join(" ")).not.toContain(diagnostic); }); it("passes headers in compilation request", async () => { diff --git a/tests/server/services/local-compiler.test.ts b/tests/server/services/local-compiler.test.ts index fa5a05ba0..0d9df89c3 100644 --- a/tests/server/services/local-compiler.test.ts +++ b/tests/server/services/local-compiler.test.ts @@ -129,16 +129,19 @@ describe("LocalCompiler public compile behavior", () => { it("normalizes compiler stderr and rejects failed compilation", async () => { const workspace = await createSketchWorkspace(); + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; vi.spyOn(ProcessExecutor.prototype, "execute").mockResolvedValue({ code: 1, stdout: "", - stderr: "/tmp/temp/abc123/sketch.cpp:4: error: invalid syntax", + stderr: `/tmp/temp/abc123/sketch.cpp:4: error: ${diagnostic}`, error: new Error("g++ failed"), }); + const errorLog = vi.spyOn(Logger.prototype, "error"); await expect( new LocalCompiler().compile(workspace.sketchFile, workspace.executableFile), - ).rejects.toThrow("sketch.ino:4: error: invalid syntax"); + ).rejects.toThrow(`sketch.ino:4: error: ${diagnostic}`); + expect(errorLog.mock.calls.flat().join(" ")).not.toContain(diagnostic); }); it("retries a transient compiler failure and succeeds on the second attempt", async () => { diff --git a/tests/server/services/process-controller.test.ts b/tests/server/services/process-controller.test.ts index 50d5e5c8f..9bf88a14b 100644 --- a/tests/server/services/process-controller.test.ts +++ b/tests/server/services/process-controller.test.ts @@ -1,7 +1,28 @@ -import { describe, it, expect } from "vitest"; +import { describe, it, expect, vi } from "vitest"; import { ProcessController } from "../../../server/services/process-controller"; +import { Logger } from "../../../shared/logger"; describe("ProcessController — unit", () => { + it("forwards stderr without logging its diagnostic contents", async () => { + const pc = new ProcessController(); + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; + let stderr = ""; + const debug = vi.spyOn(Logger.prototype, "debug"); + pc.onStderr((chunk) => { stderr += chunk.toString(); }); + const closed = new Promise((resolve, reject) => { + const timeout = setTimeout(() => reject(new Error("timed out waiting for stderr close")), 2_000); + pc.onClose(() => { + clearTimeout(timeout); + resolve(); + }); + }); + await pc.spawn("node", ["-e", "process.stderr.write('F01_COMPILER_' + 'DIAGNOSTIC_SENTINEL')"]); + await closed; + + expect(stderr).toBe(diagnostic); + expect(debug.mock.calls.flat().join(" ")).not.toContain(diagnostic); + }); + it("forwards stdout data to registered listeners (pre/post-spawn)", async () => { const pc = new ProcessController(); diff --git a/tests/server/services/process-executor.test.ts b/tests/server/services/process-executor.test.ts new file mode 100644 index 000000000..d60f92e52 --- /dev/null +++ b/tests/server/services/process-executor.test.ts @@ -0,0 +1,39 @@ +import { EventEmitter } from "node:events"; +import type { ChildProcess } from "node:child_process"; +import { beforeEach, describe, expect, it, vi } from "vitest"; +import { Logger } from "../../../shared/logger"; + +const { spawnMock } = vi.hoisted(() => ({ spawnMock: vi.fn() })); +vi.mock("node:child_process", () => ({ spawn: spawnMock })); + +import { ProcessExecutor } from "../../../server/services/process-executor"; + +describe("ProcessExecutor diagnostic logging", () => { + beforeEach(() => { + spawnMock.mockReset(); + }); + + it("retains compiler stderr for callers without copying it into logs or errors", async () => { + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; + const child = new EventEmitter() as ChildProcess; + Object.assign(child, { + stdout: new EventEmitter(), + stderr: new EventEmitter(), + pid: 1234, + }); + spawnMock.mockImplementation(() => { + queueMicrotask(() => { + child.stderr?.emit("data", Buffer.from(diagnostic)); + child.emit("close", 1); + }); + return child; + }); + const warn = vi.spyOn(Logger.prototype, "warn"); + + const result = await new ProcessExecutor().execute("echo", [], { timeout: 0 }); + + expect(result.stderr).toBe(diagnostic); + expect(result.error?.message).not.toContain(diagnostic); + expect(warn.mock.calls.flat().join(" ")).not.toContain(diagnostic); + }); +}); diff --git a/tests/server/services/sandbox/stream-handler.test.ts b/tests/server/services/sandbox/stream-handler.test.ts index d56141358..d43023380 100644 --- a/tests/server/services/sandbox/stream-handler.test.ts +++ b/tests/server/services/sandbox/stream-handler.test.ts @@ -1,5 +1,6 @@ import { describe, it, expect, vi, beforeEach } from "vitest"; import { StreamHandler } from "../../../../server/services/sandbox/stream-handler"; +import { Logger } from "../../../../shared/logger"; // Minimal mock for IProcessController const createMockController = () => ({ @@ -236,5 +237,21 @@ describe("StreamHandler", () => { expect(callbacks.onError).toHaveBeenCalledWith("some error"); }); + + it("does not log diagnostic text while forwarding it to the client", () => { + const state = createMockState(); + const callbacks = createMockCallbacks(); + const warn = vi.spyOn(Logger.prototype, "warn"); + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; + + handler.handleParsedLine( + { type: "text", line: diagnostic }, + state as any, + callbacks, + ); + + expect(callbacks.onError).toHaveBeenCalledWith(diagnostic); + expect(warn.mock.calls.flat().join(" ")).not.toContain(diagnostic); + }); }); }); diff --git a/tests/shared/logger.test.ts b/tests/shared/logger.test.ts index 83bcf5039..a7e6c620d 100644 --- a/tests/shared/logger.test.ts +++ b/tests/shared/logger.test.ts @@ -240,5 +240,25 @@ describe("Logger", () => { it("should register process error handlers without throwing", () => { expect(() => initializeGlobalErrorHandlers()).not.toThrow(); }); + + it("does not print an unhandled rejection's diagnostic text", () => { + const diagnostic = "F01_COMPILER_DIAGNOSTIC_SENTINEL"; + logger.debug("safe buffered context"); + initializeGlobalErrorHandlers(); + const handler = process.listeners("unhandledRejection").at(-1) as ( + reason: unknown, + promise: Promise, + ) => void; + const uncaughtHandler = process.listeners("uncaughtException").at(-1) as ( + error: Error, + ) => void; + try { + handler(new Error(diagnostic), Promise.resolve()); + expect(errorSpy.mock.calls.flat().join(" ")).not.toContain(diagnostic); + } finally { + process.off("unhandledRejection", handler); + process.off("uncaughtException", uncaughtHandler); + } + }); }); });