Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
99 changes: 95 additions & 4 deletions apps/packaged/src/logging.ts
Original file line number Diff line number Diff line change
Expand Up @@ -218,26 +218,117 @@ export function createPackagedDesktopLogger(paths: PackagedNamespacePaths): Pack
warn: console.warn.bind(console),
};

// Packaged Electron on Windows / Linux has no controlling terminal:
// `process.stdout` / `process.stderr` are typically detached or
// piped to a closed handle, so the very first `console.info(...)`
// a renderer lifecycle handler fires (e.g. `did-start-loading`)
// raises `Error: EPIPE: broken pipe, write` from
// `node:internal/streams/writable:508`. The error escapes the
// wrapper because the throws happen *inside* `Writable.write`, not
// at the call site, and lands in the packaged main process as an
// uncaught exception that crashes the whole app with Electron's
// native "JavaScript error in main process" dialog.
//
// The structured file logger above already swallows its own
// append failures (see `appendDesktopLogLine`). This wrapper does
// the same for the stdout / stderr echo: only the two known-safe
// stream-closure error codes are swallowed, and the matcher is
// intentionally narrow (a future `code: 'EACCES'`-style regression
// that broadens the filter trips the regression test in
// `tests/logging.test.ts`).
//
// This try/catch alone is NOT sufficient to stop the crash: it only
// catches a *synchronous* throw, and a detached stdout/stderr pipe
// fails asynchronously instead. See `installStdioErrorGuard` below
// for the layer that actually covers that path.
const safeEcho = (fn: (...a: unknown[]) => void) => (...args: unknown[]) => {
if (!echo) return;
try {
fn(...args);
} catch (error) {
if (isHarmlessStdoutError(error)) return;
throw error;
}
};

console.log = (...args: unknown[]) => {
logger.info("console.log", { args });
if (echo) originalConsole.log(...args);
safeEcho(originalConsole.log)(...args);
};
console.info = (...args: unknown[]) => {
logger.info("console.info", { args });
if (echo) originalConsole.info(...args);
safeEcho(originalConsole.info)(...args);
};
console.warn = (...args: unknown[]) => {
logger.warn("console.warn", { args });
if (echo) originalConsole.warn(...args);
safeEcho(originalConsole.warn)(...args);
};
console.error = (...args: unknown[]) => {
logger.error("console.error", { args });
if (echo) originalConsole.error(...args);
safeEcho(originalConsole.error)(...args);
};

// safeEcho's try/catch only covers a *synchronous* throw. It does not
// cover this failure mode: verified live on a packaged Windows build
// where safeEcho alone did not stop the crash. See installStdioErrorGuard.
installStdioErrorGuard([process.stdout, process.stderr]);

return logger;
}

/**
* Second, independent layer on top of `safeEcho` above. `safeEcho`'s
* try/catch only catches a *synchronous* throw from the echo call, but
* `Writable#write` on a detached stdout/stderr pipe (no controlling
* terminal — the packaged Electron case) fails *asynchronously*
* instead: Node's internal `onwriteError` path schedules the stream's
* own `'error'` event via `process.nextTick` during `destroy()`, so by
* the time it fires, the `try { fn(...args) }` call has already
* returned normally and there is nothing left on the stack to catch.
*
* This is easy to miss because the resulting uncaught exception's
* `.stack` is misleading: V8 fixes `.stack` at `Error` *construction*
* time — deep inside the synchronous write attempt, which includes
* this file's `safeEcho` frames — not at throw time. It looks like the
* error went through `safeEcho` and escaped it, when it actually never
* reached that catch block at all.
*
* Streams are passed in (rather than reading `process.stdout` /
* `process.stderr` directly) so this can be unit tested against fakes.
*/
export function installStdioErrorGuard(streams: Iterable<NodeJS.WritableStream>): void {
for (const stream of streams) {
stream.on("error", (error) => {
if (isHarmlessStdoutError(error)) return;
throw error;
});
}
}

/**
* Recognise the two known-harmless stream-closure error codes that
* packaged Electron's stdout / stderr can raise when the underlying
* pipe has been detached (no controlling terminal, redirected to a
* closed handle, or explicitly `.destroy()`ed by the host).
*
* - `EPIPE` — classic POSIX broken-pipe on `write`
* - `ERR_STREAM_DESTROYED` — Node's "stream was destroyed" state
*
* The matcher is intentionally narrow: it requires the structured
* `code` property to be present and to equal one of the two known
* values. A bare `Error` with "broken pipe" in its message but no
* `code` is rejected so that real I/O failures (e.g. an EACCES on
* a file write that happens to mention pipes) are not silently
* dropped. Tests in `tests/logging.test.ts` pin both edges.
*
* @see https://github.com/nexu-io/open-design/issues/6964
*/
export function isHarmlessStdoutError(error: unknown): boolean {
if (error == null || typeof error !== "object") return false;
const code = (error as { code?: unknown }).code;
return code === "EPIPE" || code === "ERR_STREAM_DESTROYED";
}

export function attachPackagedDesktopProcessLogging(options: {
logger: PackagedDesktopLogger;
paths: PackagedNamespacePaths;
Expand Down
184 changes: 183 additions & 1 deletion apps/packaged/tests/logging.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,8 @@
* @see https://github.com/nexu-io/open-design/issues/895
*/

import { mkdtempSync, rmSync } from 'node:fs';
import { EventEmitter } from 'node:events';
import { mkdtempSync, readFileSync, rmSync } from 'node:fs';
import { join } from 'node:path';
import { tmpdir } from 'node:os';

Expand All @@ -25,7 +26,9 @@ import {
createPackagedDesktopLogger,
createFatalUncaughtExceptionHandler,
createFatalUnhandledRejectionHandler,
installStdioErrorGuard,
isHarmlessSocketOptionError,
isHarmlessStdoutError,
type PackagedDesktopLogger,
} from '../src/logging.js';
import type { PackagedNamespacePaths } from '../src/paths.js';
Expand Down Expand Up @@ -146,6 +149,185 @@ describe('isHarmlessSocketOptionError (issue #895)', () => {
});
});

/**
* Regression coverage for the packaged main-process EPIPE crash that
* surfaces the first time a renderer lifecycle handler calls
* `console.info(...)` in an Electron build with no controlling
* terminal. The wrapper installed by `createPackagedDesktopLogger`
* must swallow only the two known-safe stream-closure codes
* (`EPIPE`, `ERR_STREAM_DESTROYED`) and re-throw anything else, so
* real I/O failures are not silently dropped.
*/
describe('isHarmlessStdoutError (packaged console echo EPIPE guard)', () => {
it('matches an Error with code: EPIPE', () => {
const error = new Error('write EPIPE') as NodeJS.ErrnoException;
error.code = 'EPIPE';
expect(isHarmlessStdoutError(error)).toBe(true);
});

it('matches an Error with code: ERR_STREAM_DESTROYED', () => {
const error = new Error('stream destroyed') as NodeJS.ErrnoException;
error.code = 'ERR_STREAM_DESTROYED';
expect(isHarmlessStdoutError(error)).toBe(true);
});

it('does NOT match a bare Error that mentions "broken pipe" in its message but has no code', () => {
const error = new Error('broken pipe, write');
expect(isHarmlessStdoutError(error)).toBe(false);
});

it('does NOT match an unrelated errno like EACCES even if the message mentions pipes', () => {
const error = new Error('broken pipe while writing to log file') as NodeJS.ErrnoException;
error.code = 'EACCES';
expect(isHarmlessStdoutError(error)).toBe(false);
});

it('does NOT match non-objects (null, undefined, strings)', () => {
expect(isHarmlessStdoutError(null)).toBe(false);
expect(isHarmlessStdoutError(undefined)).toBe(false);
expect(isHarmlessStdoutError('EPIPE')).toBe(false);
});
});

describe('createPackagedDesktopLogger console echo EPIPE guard', () => {
it('swallows an EPIPE thrown by the original console.info echo and still records the call to the desktop log file', () => {
const root = mkdtempSync(join(tmpdir(), 'od-packaged-echo-epipe-'));
const previousEcho = process.env.OD_DESKTOP_LOG_ECHO;
// echo must be on (the default) for safeEcho to be in the path.
delete process.env.OD_DESKTOP_LOG_ECHO;
// Stub the host's console.info BEFORE constructing the logger so
// the factory captures the throwing original as `originalConsole.info`
// (the wrapper then calls safeEcho(originalConsole.info), which is
// the only place the EPIPE filter is applied — see issue #6964).
const epipe = new Error('write EPIPE') as NodeJS.ErrnoException;
epipe.code = 'EPIPE';
console.info = () => {
throw epipe;
};
const desktopLogPath = join(root, 'desktop.log');
try {
createPackagedDesktopLogger(makePaths(root, desktopLogPath));

// The wrapped call must NOT throw — the unwrapped version
// crashed the main process via an uncaught exception that
// propagated out of `Writable.write`.
expect(() =>
console.info('main window did-start-loading', { url: 'about:blank' }),
).not.toThrow();

// The wrapper must have actually run (and called the file
// logger) — not the bare stub. If the wrapper had been
// bypassed, no record would land in the desktop log file.
const line = readFileSync(desktopLogPath, 'utf8');
expect(line).toContain('console.info');
expect(line).toContain('main window did-start-loading');
} finally {
if (previousEcho == null) {
delete process.env.OD_DESKTOP_LOG_ECHO;
} else {
process.env.OD_DESKTOP_LOG_ECHO = previousEcho;
}
rmSync(root, { recursive: true, force: true });
}
});

it('still re-throws non-harmless errors thrown by the original console.error echo and records the call to the desktop log file', () => {
const root = mkdtempSync(join(tmpdir(), 'od-packaged-echo-other-'));
const previousEcho = process.env.OD_DESKTOP_LOG_ECHO;
delete process.env.OD_DESKTOP_LOG_ECHO;
// Same before/after ordering as the EPIPE case: stub the host's
// console.error BEFORE the factory so originalConsole.error
// captures the throwing stub.
const eacces = new Error('permission denied writing to log file') as NodeJS.ErrnoException;
eacces.code = 'EACCES';
console.error = () => {
throw eacces;
};
const desktopLogPath = join(root, 'desktop.log');
try {
createPackagedDesktopLogger(makePaths(root, desktopLogPath));

// The wrapper must surface non-harmless errors so real I/O
// failures are not silently dropped.
expect(() => console.error('fatal write failure')).toThrow(eacces);

// The wrapper must have actually run (and called the file
// logger BEFORE the echo) — proving the throw escaped via
// safeEcho, not via the bare stub.
const line = readFileSync(desktopLogPath, 'utf8');
expect(line).toContain('console.error');
expect(line).toContain('fatal write failure');
} finally {
if (previousEcho == null) {
delete process.env.OD_DESKTOP_LOG_ECHO;
} else {
process.env.OD_DESKTOP_LOG_ECHO = previousEcho;
}
rmSync(root, { recursive: true, force: true });
}
});
});

// Regression coverage for the gap `safeEcho`'s try/catch cannot close:
// a detached stdout/stderr pipe fails *asynchronously* (the stream
// emits its own 'error' event, e.g. from `process.nextTick` during
// internal `destroy()`), not as a synchronous throw from `.write()`.
// Reproduced live on a packaged Windows build: the crash's stack trace
// still showed `safeEcho`'s frames (because V8 fixes `.stack` at Error
// *construction* time, not throw time), which made it look like the
// try/catch had been bypassed when in fact it was never reached at all.
describe('installStdioErrorGuard (async stdio pipe-closure guard)', () => {
function fakeStream(): NodeJS.WritableStream {
return new EventEmitter() as unknown as NodeJS.WritableStream;
}

it('swallows an EPIPE emitted asynchronously on the stream, not thrown synchronously', () => {
const stream = fakeStream();
installStdioErrorGuard([stream]);

const epipe = new Error('write EPIPE') as NodeJS.ErrnoException;
epipe.code = 'EPIPE';

// This is exactly what safeEcho's try/catch cannot see: nothing on
// the call stack, just an 'error' event firing on its own.
expect(() => (stream as unknown as EventEmitter).emit('error', epipe)).not.toThrow();
});

it('swallows an ERR_STREAM_DESTROYED emitted asynchronously on the stream', () => {
const stream = fakeStream();
installStdioErrorGuard([stream]);

const destroyed = new Error('stream destroyed') as NodeJS.ErrnoException;
destroyed.code = 'ERR_STREAM_DESTROYED';

expect(() => (stream as unknown as EventEmitter).emit('error', destroyed)).not.toThrow();
});

it('re-throws a non-harmless error emitted on the stream instead of silently dropping it', () => {
const stream = fakeStream();
installStdioErrorGuard([stream]);

const eacces = new Error('permission denied') as NodeJS.ErrnoException;
eacces.code = 'EACCES';

// EventEmitter re-throws synchronously out of emit() when an
// 'error' listener itself throws.
expect(() => (stream as unknown as EventEmitter).emit('error', eacces)).toThrow(eacces);
});

it('installs an independent guard per stream (stdout failure does not depend on stderr)', () => {
const stdout = fakeStream();
const stderr = fakeStream();
installStdioErrorGuard([stdout, stderr]);

const epipe = new Error('write EPIPE') as NodeJS.ErrnoException;
epipe.code = 'EPIPE';

expect(() => (stdout as unknown as EventEmitter).emit('error', epipe)).not.toThrow();
expect(() => (stderr as unknown as EventEmitter).emit('error', epipe)).not.toThrow();
});
});

describe('createPackagedDesktopLogger log-write failures', () => {
it('drops descriptor-pressure append failures instead of throwing', () => {
const emfile = new Error('too many files') as NodeJS.ErrnoException;
Expand Down
Loading