-
Notifications
You must be signed in to change notification settings - Fork 10.6k
Expand file tree
/
Copy pathlogging.ts
More file actions
386 lines (359 loc) Β· 15.3 KB
/
Copy pathlogging.ts
File metadata and controls
386 lines (359 loc) Β· 15.3 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
import { appendFileSync } from "node:fs";
import type { SidecarStamp } from "@open-design/sidecar-proto";
import type { PackagedNamespacePaths } from "./paths.js";
const DESKTOP_LOG_ECHO_ENV = "OD_DESKTOP_LOG_ECHO";
type LogLevel = "error" | "info" | "warn";
export type PackagedDesktopLogger = {
error(message: string, meta?: Record<string, unknown>): void;
info(message: string, meta?: Record<string, unknown>): void;
warn(message: string, meta?: Record<string, unknown>): void;
};
function normalizeError(error: unknown): unknown {
if (error instanceof Error) {
return {
message: error.message,
name: error.name,
stack: error.stack,
};
}
return error;
}
/**
* Recognise known-harmless socket option errors so the packaged main
* process can swallow them instead of surfacing Electron's "JavaScript
* error in main process" dialog (issue #895).
*
* The flagship case is undici throwing `setTypeOfService EINVAL` from
* its socket setup path: certain macOS / VPN configurations refuse to
* let the kernel set the IP_TOS byte on outbound sockets. The QoS
* marking failing has no functional impact on the request β the socket
* still connects and serves traffic β so the right behaviour is to
* log + ignore, not to crash.
*
* Match strategy is intentionally narrow:
* 1. The error message must name the `setTypeOfService` syscall.
* 2. The structured `code` property is **authoritative** when
* present: it must equal `EINVAL` for the error to qualify.
* A `code` of anything else (e.g. `EACCES`) is treated as a
* contradicting signal and the filter rejects the match β
* otherwise an `EACCES` permission failure with a stale or
* copy-pasted `EINVAL` substring in the message would slip
* through.
* 3. Only when `code` is absent (some libuv builds don't populate
* it on raw thrown Errors) do we fall back to looking for the
* `EINVAL` token in the message.
*
* We never swallow every `EINVAL`: that code is raised by plenty of
* real bugs (bad config values, malformed arguments to other
* syscalls). Exported so a unit test can pin the exact shape this
* branch matches.
*/
export function isHarmlessSocketOptionError(value: unknown): boolean {
if (!(value instanceof Error)) return false;
const message = typeof value.message === "string" ? value.message : "";
if (!message) return false;
if (!message.includes("setTypeOfService")) return false;
const code = (value as NodeJS.ErrnoException).code;
if (typeof code === "string" && code.length > 0) {
// Structured code present β it has to be EINVAL. Anything else
// (EACCES, EPERM, ECONNRESET, β¦) is a contradicting signal and
// we let it crash so real bugs don't get hidden.
return code === "EINVAL";
}
// No structured code: fall back to message-based detection. The
// libuv error string is `<syscall> <errcode>` so the EINVAL token
// appears alongside the syscall name.
return message.includes("EINVAL");
}
/**
* Build the named `uncaughtException` handler used by
* `attachPackagedDesktopProcessLogging`. Exposed as its own factory
* so a unit test can drive it without bringing up the full logging
* pipeline.
*
* Behaviour contract (issue #906 review):
* - Harmless `setTypeOfService EINVAL` shapes from undici socket
* internals are logged at warn level and the function returns
* silently. The process continues running.
* - Anything else is logged at error level, then the handler
* **removes itself from `process.uncaughtException` listeners**
* and re-throws via `setImmediate`. Removing the listener first
* is critical: without it, the re-throw re-enters the same
* handler, schedules another setImmediate, and the packaged
* main process spins forever instead of terminating β
* reproduced and called out by mrcfps + lefarcen on the first
* #906 review pass. With the listener gone the next throw has
* no `uncaughtException` listener to land in, Node's default
* crash path takes over, and Electron's native "JavaScript
* error in main process" dialog renders as it did before this
* code existed.
*/
export function createFatalUncaughtExceptionHandler(
logger: PackagedDesktopLogger,
): (error: unknown) => void {
const handler = (error: unknown): void => {
if (isHarmlessSocketOptionError(error)) {
logger.warn("packaged desktop swallowed harmless socket option error", { error });
return;
}
logger.error("packaged desktop fatal uncaught exception", { error });
process.removeListener("uncaughtException", handler);
setImmediate(() => {
throw error;
});
};
return handler;
}
/**
* Parallel factory for the `unhandledRejection` listener installed by
* `attachPackagedDesktopProcessLogging`. The harmless / fall-through
* split must match `createFatalUncaughtExceptionHandler`: harmless
* `setTypeOfService EINVAL` rejections log at warn and return,
* anything else logs at error, removes the listener, and re-throws
* via `setImmediate`.
*
* Without the detach + rethrow a non-harmless rejection would land in
* this log line and silently keep the process alive, which would hide
* real main-process bugs from Node/Electron's default fail-fast path
* (the exact regression Siri-Ray and the codex P2 thread flagged on
* the parallel desktop filter in PR #1298). The same matcher feeds
* both factories, so the apps/desktop sibling stays in lockstep.
*/
export function createFatalUnhandledRejectionHandler(
logger: PackagedDesktopLogger,
): (reason: unknown) => void {
const handler = (reason: unknown): void => {
if (isHarmlessSocketOptionError(reason)) {
logger.warn("packaged desktop swallowed harmless socket option rejection", { reason });
return;
}
logger.error("packaged desktop unhandled rejection", { reason });
process.removeListener("unhandledRejection", handler);
setImmediate(() => {
throw reason;
});
};
return handler;
}
function normalizeMeta(meta: Record<string, unknown> | undefined): Record<string, unknown> | undefined {
if (meta == null) return undefined;
return Object.fromEntries(
Object.entries(meta).map(([key, value]) => [key, key === "error" || key === "reason" ? normalizeError(value) : value]),
);
}
function serializeMessage(level: LogLevel, message: string, meta?: Record<string, unknown>): string {
const timestamp = new Date().toISOString();
try {
return `${JSON.stringify({
level,
message,
timestamp,
...(meta == null ? {} : { meta: normalizeMeta(meta) }),
})}\n`;
} catch (error) {
return `${JSON.stringify({
level,
message,
timestamp,
meta: {
serializationError: error instanceof Error ? error.message : String(error),
},
})}\n`;
}
}
type DesktopLogAppend = (path: string, data: string, encoding: BufferEncoding) => void;
export function appendDesktopLogLine(
desktopLogPath: string,
line: string,
append: DesktopLogAppend = appendFileSync,
): boolean {
try {
append(desktopLogPath, line, "utf8");
return true;
} catch {
// Logging must never be the thing that crashes the packaged app.
// Under offline retry storms the log file itself can hit EMFILE;
// swallowing the write breaks the fatal log -> append failure loop.
return false;
}
}
export function createPackagedDesktopLogger(paths: PackagedNamespacePaths): PackagedDesktopLogger {
const echo = process.env[DESKTOP_LOG_ECHO_ENV] !== "0";
const write = (level: LogLevel, message: string, meta?: Record<string, unknown>) => {
appendDesktopLogLine(paths.desktopLogPath, serializeMessage(level, message, meta));
};
const logger: PackagedDesktopLogger = {
error(message, meta) {
write("error", message, meta);
},
info(message, meta) {
write("info", message, meta);
},
warn(message, meta) {
write("warn", message, meta);
},
};
const originalConsole = {
error: console.error.bind(console),
info: console.info.bind(console),
log: console.log.bind(console),
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 });
safeEcho(originalConsole.log)(...args);
};
console.info = (...args: unknown[]) => {
logger.info("console.info", { args });
safeEcho(originalConsole.info)(...args);
};
console.warn = (...args: unknown[]) => {
logger.warn("console.warn", { args });
safeEcho(originalConsole.warn)(...args);
};
console.error = (...args: unknown[]) => {
logger.error("console.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;
stamp: SidecarStamp;
}): void {
const { logger, paths, stamp } = options;
logger.info("packaged desktop starting", {
daemonDataRoot: paths.dataRoot,
electronUserDataRoot: paths.electronUserDataRoot,
executablePath: process.execPath,
logPath: paths.desktopLogPath,
namespace: stamp.namespace,
pid: process.pid,
ppid: process.ppid,
resourceRoot: paths.resourceRoot,
runtimeRoot: paths.runtimeRoot,
source: stamp.source,
});
process.on("uncaughtExceptionMonitor", (error) => {
logger.error("packaged desktop uncaught exception", { error });
});
// Defensive filter for known-harmless network errors. undici can throw
// `setTypeOfService EINVAL` from socket internals on certain macOS /
// VPN configurations (issue #895): the kernel rejects setting the
// IP_TOS byte on the outbound socket, but the connection itself is
// healthy β we just don't get the QoS / DSCP marking, which the app
// doesn't depend on. Without this filter the rejection bubbles to
// Electron's default handler and surfaces as a native "JavaScript
// error in main process" dialog the next time anything in the
// renderer does a fetch (e.g. opening Settings β Pets β Community).
//
// For non-harmless errors the handler restores Node's default
// uncaughtException behaviour: it removes itself from the listener
// list and re-throws via `setImmediate`. With no `uncaughtException`
// handlers registered, Node's default crash path takes over (stack
// trace + non-zero exit) and Electron's own "JavaScript error in
// main process" dialog renders as it would have before this code
// existed. See `createFatalUncaughtExceptionHandler` for the
// unit-tested factory.
process.on("uncaughtException", createFatalUncaughtExceptionHandler(logger));
// The unhandledRejection handler must mirror the uncaughtException
// policy: harmless EINVAL shapes are swallowed, every other reason
// takes the fail-fast path so a real main-process bug surfaces
// through Node/Electron's default crash semantics instead of being
// hidden as a log line. See `createFatalUnhandledRejectionHandler`.
process.on("unhandledRejection", createFatalUnhandledRejectionHandler(logger));
process.on("beforeExit", (code) => {
logger.info("packaged desktop beforeExit", { code });
});
process.on("exit", (code) => {
logger.info("packaged desktop exit", { code });
});
}