Files
learnharness/tests/desktop-logger.test.ts
T

199 lines
8.8 KiB
TypeScript

import assert from "node:assert/strict";
import { spawn } from "node:child_process";
import { EventEmitter, once } from "node:events";
import fs from "node:fs";
import { createRequire } from "node:module";
import os from "node:os";
import path from "node:path";
import { describe, it } from "node:test";
import type { TestContext } from "node:test";
import { fileURLToPath } from "node:url";
import { createContext, runInContext } from "node:vm";
const require = createRequire(import.meta.url);
const { createDesktopLogger, MAX_LOG_BYTES } = require("../electron/desktop-logger.cjs");
const mainFile = fileURLToPath(new URL("../electron/main.cjs", import.meta.url));
const mainRequire = createRequire(mainFile);
function directory(t: TestContext) {
const dir = fs.mkdtempSync(path.join(os.tmpdir(), "lh-desktop-logger-"));
t.after(() => fs.rmSync(dir, { recursive: true, force: true }));
return dir;
}
function retained(dir: string, cap: number) {
const names = fs.readdirSync(dir).sort();
assert.ok(names.length <= 2);
for (const name of names) {
assert.ok(["main.log", "main.log.1"].includes(name));
assert.ok(fs.statSync(path.join(dir, name)).size <= cap, `${name} exceeds the byte cap`);
}
return ["main.log.1", "main.log"].filter(name => names.includes(name)).map(name => fs.readFileSync(path.join(dir, name), "utf8")).join("");
}
class Output extends EventEmitter {
writes = 0;
write() { this.writes++; return true; }
}
describe("bounded desktop logs", () => {
it("rotates repeated floods within two 5 MiB files and keeps the latest entries", (t) => {
const dir = directory(t);
assert.equal(MAX_LOG_BYTES, 5 * 1024 * 1024);
const logger = createDesktopLogger({ directory: () => dir });
for (let i = 0; i < 35; i++) logger.log(`${i} ${"x".repeat(1024 * 1024)}`);
logger.log("most recent diagnostic");
const text = retained(dir, MAX_LOG_BYTES);
assert.match(text, /most recent diagnostic\n$/);
assert.doesNotMatch(text, /\] 0 /);
});
it("trims both existing files on startup using a bounded tail read", (t) => {
const dir = directory(t);
for (const name of ["main.log", "main.log.1"]) {
const file = path.join(dir, name);
// Unix creates a sparse hole automatically. Windows can allocate the
// entire gap, so keep that fixture small while still exceeding the cap.
const legacySize = process.platform === "win32" ? MAX_LOG_BYTES * 3 : 200 * 1024 ** 3;
const fd = fs.openSync(file, "w");
fs.writeSync(fd, Buffer.from(`recent ${name}\n`), 0, Buffer.byteLength(`recent ${name}\n`), legacySize);
fs.closeSync(fd);
}
let largestRead = 0;
const filesystem = { ...fs, readSync: (...args: Parameters<typeof fs.readSync>) => {
largestRead = Math.max(largestRead, (args[1] as Buffer).byteLength);
return fs.readSync(...args);
} };
const logger = createDesktopLogger({ directory: () => dir, filesystem });
logger.initialize();
assert.ok(largestRead <= MAX_LOG_BYTES);
assert.match(retained(dir, MAX_LOG_BYTES), /recent main.log\n$/);
assert.match(fs.readFileSync(path.join(dir, "main.log.1"), "utf8"), /recent main.log.1\n$/);
logger.log("after restart");
createDesktopLogger({ directory: () => dir }).log("after second restart");
assert.match(retained(dir, MAX_LOG_BYTES), /after second restart\n$/);
});
it("caps one oversized Unicode entry by bytes, retaining valid UTF-8 and its suffix", (t) => {
const dir = directory(t);
const logger = createDesktopLogger({ directory: () => dir, maxFileBytes: 256 });
logger.log(`${"🙂".repeat(1000)}latest`);
const text = retained(dir, 256);
assert.match(text, /\[truncated\]/);
assert.match(text, /latest\n$/);
assert.ok(!text.includes("�"));
});
it("disables stdout permanently on asynchronous errors, with one file-only diagnostic", (t) => {
const dir = directory(t);
const stdout = new Output();
const stderr = new Output();
const logger = createDesktopLogger({ directory: () => dir, stdout, stderr });
logger.log("before failure");
const error = Object.assign(new Error("broken pipe"), { code: "EPIPE" });
stdout.emit("error", error);
stdout.emit("drain");
stdout.emit("error", error);
stderr.emit("error", error);
stderr.emit("error", error);
logger.log("after failure");
assert.equal(stdout.writes, 1);
const text = retained(dir, MAX_LOG_BYTES);
assert.equal(text.match(/stdout disabled/g)?.length, 1);
assert.equal(text.match(/stderr disabled/g)?.length, 1);
assert.match(text, /after failure/);
});
it("handles synchronous write failures and bounds buffering under backpressure", (t) => {
const dir = directory(t);
const stdout = new Output();
stdout.write = () => { stdout.writes++; throw Object.assign(new Error("closed"), { code: "EPIPE" }); };
const logger = createDesktopLogger({ directory: () => dir, stdout });
assert.doesNotThrow(() => { logger.log("first"); logger.log("second"); });
assert.equal(stdout.writes, 1);
const slow = new Output();
slow.write = () => { slow.writes++; return false; };
const slowLogger = createDesktopLogger({ directory: () => dir, stdout: slow });
for (let i = 0; i < 100; i++) slowLogger.log(`slow ${i}`);
assert.equal(slow.writes, 1);
slow.emit("drain");
slowLogger.log("drained");
assert.equal(slow.writes, 2);
});
it("never propagates full-disk or rotation errors or mirrors file-only errors", (t) => {
const dir = directory(t);
const stdout = new Output();
const logger = createDesktopLogger({ directory: () => dir, stdout, filesystem: {
...fs, appendFileSync() { throw Object.assign(new Error("disk full"), { code: "ENOSPC" }); },
} });
assert.doesNotThrow(() => logger.log("uncaught: diagnostic", { fileOnly: true }));
assert.equal(stdout.writes, 0);
const file = path.join(dir, "main.log");
fs.writeFileSync(file, "old\n".repeat(60));
const blockedRotation = createDesktopLogger({ directory: () => dir, maxFileBytes: 256, filesystem: {
...fs, renameSync() { throw new Error("rotation denied"); },
} });
assert.doesNotThrow(() => blockedRotation.log("new".repeat(100)));
assert.equal(fs.statSync(file).size, 240, "a failed rotation must not append beyond the cap");
});
});
describe("desktop shell logging integration", () => {
it("records uncaught errors without touching stdout", (t) => {
const dir = directory(t);
const handlers = new Map<string, (error: Error) => void>();
const stdout = new Output();
const context = createContext({
require: (id: string) => id === "electron" ? { app: { setName() {}, getPath: () => dir, requestSingleInstanceLock: () => false, quit() {} } } : mainRequire(id),
process: { argv: [], env: {}, stdout, stderr: new Output(), on: (name: string, handler: (error: Error) => void) => handlers.set(name, handler) },
__dirname: path.dirname(mainFile),
});
runInContext(fs.readFileSync(mainFile, "utf8"), context, { filename: mainFile });
handlers.get("uncaughtException")!(new Error("original failure"));
assert.equal(stdout.writes, 0);
assert.match(retained(path.join(dir, "logs"), MAX_LOG_BYTES), /uncaught: Error: original failure/);
});
it("survives a real closed stdout pipe, records EPIPE once, and exits normally", async (t) => {
const dir = directory(t);
const source = `
const fs = require('node:fs');
const vm = require('node:vm');
const mainFile = ${JSON.stringify(mainFile)};
const mainRequire = require('node:module').createRequire(mainFile);
const context = vm.createContext({
require: id => id === 'electron' ? {app: {setName() {}, getPath: () => ${JSON.stringify(dir)}, requestSingleInstanceLock: () => false, quit() {}}} : mainRequire(id),
process, console, __dirname: require('node:path').dirname(mainFile)
});
vm.runInContext(fs.readFileSync(mainFile, 'utf8'), context, {filename: mainFile});
process.once('message', () => {
vm.runInContext('log("trigger broken pipe")', context);
setTimeout(() => {
vm.runInContext('log("still alive after broken pipe")', context);
process.disconnect();
}, 100);
});
process.send('ready');
`;
const child = spawn(process.execPath, ["-e", source], { stdio: ["ignore", "pipe", "pipe", "ipc"] });
t.after(() => { if (child.exitCode === null) child.kill("SIGKILL"); });
const deadline = setTimeout(() => child.kill("SIGKILL"), 5000);
t.after(() => clearTimeout(deadline));
let stderr = "";
child.stderr!.on("data", chunk => { stderr = (stderr + chunk).slice(-4000); });
const exited = once(child, "exit");
await Promise.race([once(child, "message"), exited.then(() => { throw new Error(`Fixture exited before ready: ${stderr}`); })]);
child.stdout!.destroy();
child.send("start");
const [code, signal] = await exited;
assert.equal(signal, null, stderr);
assert.equal(code, 0, stderr);
const text = retained(path.join(dir, "logs"), MAX_LOG_BYTES);
assert.equal(text.match(/EPIPE/g)?.length, 1);
assert.doesNotMatch(text, /uncaught:/);
assert.match(text, /still alive after broken pipe/);
assert.ok(Buffer.byteLength(text) < 1024, "a closed pipe must not produce a log flood");
});
});