Skip to content

Commit 5f05de2

Browse files
os-zhuangclaude
andauthored
fix(core): ObjectLogger file destination silently no-ops in ESM builds (#3116)
Fixes #3110. `openFileStream` loaded `fs` with a lazy `require()` to keep the browser-safe logger entry out of the `fs` bundle graph. esbuild rewrites that to its `__require` shim in the ESM output, which throws `Dynamic require of "fs" is not supported`, and the surrounding bare `catch {}` swallowed it. The workspace is `type: module`, so every Node ESM consumer — `os serve`, `os dev` — silently got no file logging at all, while the CJS build kept working. Load the builtin through `process.getBuiltinModule` instead: a plain method call, opaque to bundlers, working in both module systems, still behind the existing `typeof process` guard. `require` stays as a fallback for Node < 20.16, which predates it. A `file` destination that cannot be opened now reports on stderr rather than vanishing — the silence is what kept this hidden. Opening the destination for the first time also exposed three faults that were unreachable while it never opened: - `child()` passed `file` to the constructor, which opens eagerly, so every child opened a second stream to the same path and immediately orphaned it — despite the "no double-open" comment. - Destroying a child ended the stream its parent and siblings were still writing to. - `createWriteStream` reports open failures asynchronously; an 'error' event with no listener is an uncaught exception, so an unwritable log path would have taken the host process down. The regression test bundles the entry with esbuild and spawns a real `node`, because under vitest the source runs through vite-node where `require` IS defined — an in-process test of this code passes against the broken version. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
1 parent fdc244e commit 5f05de2

5 files changed

Lines changed: 222 additions & 13 deletions

File tree

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,7 @@
1+
---
2+
"@objectstack/core": patch
3+
---
4+
5+
**`createLogger({ file })` now actually writes the file under ESM.** `openFileStream` loaded `fs` with a lazy `require()` to keep the browser-safe logger entry out of the `fs` bundle graph; esbuild rewrites that to its `__require` shim in the ESM output, which throws `Dynamic require of "fs" is not supported`, and a bare `catch {}` swallowed it. Since the workspace is `type: module`, every Node ESM consumer — `os serve`, `os dev` — silently got no file logging at all, while the CJS build kept working. The builtin now loads via `process.getBuiltinModule` (opaque to bundlers, works in both module systems, with a `require` fallback for Node < 20.16), and a `file` destination that cannot be opened reports itself on stderr instead of disappearing.
6+
7+
Turning the destination back on also fixed three faults that were unreachable while it never opened: `child()` opened a second stream per child and orphaned it, destroying a child logger closed the stream its parent and siblings were still writing to, and an async open failure (e.g. an unwritable path) hit an `'error'` event with no listener and took the process down.

packages/core/package.json

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525
},
2626
"devDependencies": {
2727
"@types/node": "^26.1.1",
28+
"esbuild": "^0.28.1",
2829
"typescript": "^6.0.3",
2930
"vitest": "^4.1.10"
3031
},
Lines changed: 119 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,119 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
//
3+
// Regression: `createLogger({ file })` must actually write the file when the
4+
// logger is consumed as ESM (#3110). `openFileStream` used to `require('fs')`
5+
// to keep `fs` out of the browser bundle graph; esbuild rewrites that to its
6+
// `__require` shim in the ESM output, which throws `Dynamic require of "fs" is
7+
// not supported`, and the surrounding `catch {}` swallowed it. Every Node ESM
8+
// consumer — `os serve`, `os dev`, the whole workspace is `type: module` —
9+
// silently got no file logging, while the CJS build kept working.
10+
//
11+
// These have to bundle and spawn a real `node`: under vitest the source runs
12+
// through vite-node, where `require` IS defined, so an in-process test of this
13+
// code passes against the broken version. Exercising the shipped shape is the
14+
// only thing that fails on the bug.
15+
16+
import { describe, it, expect, beforeAll, afterAll } from 'vitest';
17+
import { build } from 'esbuild';
18+
import { spawnSync } from 'node:child_process';
19+
import { mkdtempSync, rmSync, existsSync, readFileSync } from 'node:fs';
20+
import { tmpdir } from 'node:os';
21+
import { join } from 'node:path';
22+
import { fileURLToPath, pathToFileURL } from 'node:url';
23+
24+
const here = fileURLToPath(new URL('.', import.meta.url));
25+
26+
let workdir: string;
27+
let bundleHref: string;
28+
let bundlePath: string;
29+
30+
// Mirrors the ESM half of tsup.config.ts — the logger entry, bundled, es2020.
31+
// Keep in sync if that config's format/target change.
32+
beforeAll(async () => {
33+
workdir = mkdtempSync(join(tmpdir(), 'os-logger-esm-'));
34+
bundlePath = join(workdir, 'logger.mjs');
35+
await build({
36+
entryPoints: [join(here, 'logger.ts')],
37+
outfile: bundlePath,
38+
bundle: true,
39+
format: 'esm',
40+
platform: 'node',
41+
target: 'es2020',
42+
});
43+
bundleHref = pathToFileURL(bundlePath).href;
44+
}, 30_000);
45+
46+
afterAll(() => {
47+
rmSync(workdir, { recursive: true, force: true });
48+
});
49+
50+
/** Run `body` as real Node ESM with `createLogger` imported from the bundle. */
51+
function runEsm(body: string) {
52+
const source = `import { createLogger } from ${JSON.stringify(bundleHref)};\n${body}`;
53+
const result = spawnSync(process.execPath, ['--input-type=module', '-e', source], {
54+
cwd: workdir,
55+
encoding: 'utf8',
56+
});
57+
return { status: result.status, stdout: result.stdout ?? '', stderr: result.stderr ?? '' };
58+
}
59+
60+
describe('ObjectLogger file destination under ESM (#3110)', () => {
61+
it('writes the configured file when imported as ESM', () => {
62+
const logfile = join(workdir, 'app.log');
63+
const run = runEsm(`
64+
const l = createLogger({ format: 'text', file: ${JSON.stringify(logfile)} });
65+
l.info('hello from esm');
66+
await l.destroy();
67+
`);
68+
69+
expect(run.stderr).toBe('');
70+
expect(run.status).toBe(0);
71+
expect(existsSync(logfile)).toBe(true);
72+
expect(readFileSync(logfile, 'utf8')).toContain('hello from esm');
73+
});
74+
75+
it('does not reach esbuild\'s dynamic-require shim to load fs', () => {
76+
// The precise failure mode, asserted on the artifact so the diagnosis
77+
// stays attached to the test if a lazy `require` is ever reintroduced.
78+
const code = readFileSync(bundlePath, 'utf8');
79+
expect(code.slice(code.indexOf('openFileStream'))).not.toMatch(/__require\(["'](?:node:)?fs["']\)/);
80+
});
81+
82+
it('reports an unusable file path on stderr instead of dropping it silently', () => {
83+
// A directory is never a valid log file. `createWriteStream` reports
84+
// EISDIR asynchronously, so this also covers the 'error' event: with no
85+
// listener it would be an uncaught exception and a non-zero exit.
86+
const run = runEsm(`
87+
const l = createLogger({ format: 'text', file: ${JSON.stringify(workdir)} });
88+
l.info('console logging must continue');
89+
await l.destroy();
90+
await new Promise((r) => setTimeout(r, 50));
91+
console.log('SURVIVED');
92+
`);
93+
94+
expect(run.status).toBe(0);
95+
expect(run.stdout).toContain('console logging must continue');
96+
expect(run.stdout).toContain('SURVIVED');
97+
expect(run.stderr).toContain('file logging disabled');
98+
});
99+
100+
it('keeps the shared stream alive when a child logger is destroyed', () => {
101+
// `child()` shares the opener's stream, so a child's teardown must not
102+
// end it: the parent's next write would hit 'write after end' — fatal,
103+
// and unreachable until file logging actually opened under ESM.
104+
const logfile = join(workdir, 'child.log');
105+
const run = runEsm(`
106+
const parent = createLogger({ format: 'text', file: ${JSON.stringify(logfile)} });
107+
const child = parent.child({ requestId: 'r1' });
108+
child.info('from child');
109+
await child.destroy();
110+
parent.info('from parent after child teardown');
111+
await parent.destroy();
112+
`);
113+
114+
expect(run.status).toBe(0);
115+
const contents = readFileSync(logfile, 'utf8');
116+
expect(contents).toContain('from child');
117+
expect(contents).toContain('from parent after child teardown');
118+
});
119+
});

packages/core/src/logger.ts

Lines changed: 92 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,39 @@ function colorEnabled(stream: { isTTY?: boolean } | undefined): boolean {
4444
return Boolean(stream?.isTTY);
4545
}
4646

47+
/**
48+
* Resolve a Node builtin without putting it in this module's import graph.
49+
*
50+
* This entry is deliberately browser-safe — `@objectstack/client` bundles it —
51+
* so `fs`/`path` must never be imported statically. A lazy `require()` used to
52+
* meet that bar, but esbuild rewrites it to the `__require` shim in the ESM
53+
* output, which throws `Dynamic require of "fs" is not supported`. Every Node
54+
* ESM consumer (`os serve`, `os dev`) therefore lost file logging (#3110).
55+
* `process.getBuiltinModule` is a plain method call — opaque to bundlers — and
56+
* works in both module systems.
57+
*/
58+
function loadNodeBuiltin<T>(id: string): T | undefined {
59+
if (typeof process === 'undefined') return undefined;
60+
61+
const getBuiltinModule = (process as { getBuiltinModule?: (id: string) => unknown }).getBuiltinModule;
62+
if (typeof getBuiltinModule === 'function') {
63+
try {
64+
return getBuiltinModule.call(process, `node:${id}`) as T;
65+
} catch {
66+
return undefined;
67+
}
68+
}
69+
70+
// Node < 20.16 / < 22.3 predates `getBuiltinModule`. Real `require` still
71+
// resolves in the CJS build; in the ESM build this is the shim that throws,
72+
// which the caller now reports rather than swallows.
73+
try {
74+
return require(id) as T;
75+
} catch {
76+
return undefined;
77+
}
78+
}
79+
4780
export class ObjectLogger implements Logger {
4881
private config: Required<Omit<LoggerConfig, 'file' | 'rotation' | 'name'>> & {
4982
file?: string;
@@ -52,6 +85,9 @@ export class ObjectLogger implements Logger {
5285
};
5386
private bindings: Record<string, any>;
5487
private fileStream?: any;
88+
/** Only the logger that opened the stream may close it — children share it. */
89+
private ownsFileStream = false;
90+
private fileLoggingDisabled = false;
5591

5692
constructor(config: Partial<LoggerConfig> = {}, bindings: Record<string, any> = {}) {
5793
this.config = {
@@ -71,14 +107,48 @@ export class ObjectLogger implements Logger {
71107
}
72108

73109
private openFileStream(path: string) {
110+
const fs = loadNodeBuiltin<typeof import('node:fs')>('fs');
111+
const nodePath = loadNodeBuiltin<typeof import('node:path')>('path');
112+
if (!fs || !nodePath) {
113+
this.disableFileLogging(path, 'no filesystem access in this runtime');
114+
return;
115+
}
116+
74117
try {
75-
// Lazy require to avoid bundling issues
76-
const fs = require('fs');
77-
const dir = require('path').dirname(path);
78-
fs.mkdirSync(dir, { recursive: true });
79-
this.fileStream = fs.createWriteStream(path, { flags: 'a' });
80-
} catch {
81-
// ignore — file logging is optional
118+
fs.mkdirSync(nodePath.dirname(path), { recursive: true });
119+
const stream = fs.createWriteStream(path, { flags: 'a' });
120+
// `createWriteStream` reports open failures (EACCES, EISDIR, …)
121+
// asynchronously. An 'error' event with no listener is fatal to the
122+
// process, so file logging must degrade here rather than take the
123+
// host down.
124+
stream.on('error', (err: Error) => this.disableFileLogging(path, err.message));
125+
this.fileStream = stream;
126+
this.ownsFileStream = true;
127+
} catch (err) {
128+
this.disableFileLogging(path, (err as Error).message);
129+
}
130+
}
131+
132+
/**
133+
* Report — once — that an explicitly configured `file` destination is not
134+
* being written, and stop trying.
135+
*
136+
* Deliberately not routed through `write()`: this says the logger cannot
137+
* honour its own config, so `level` must not filter it. The bare `catch {}`
138+
* this replaces is exactly how #3110 stayed hidden.
139+
*/
140+
private disableFileLogging(path: string, reason: string) {
141+
this.fileStream = undefined;
142+
this.ownsFileStream = false;
143+
if (this.fileLoggingDisabled) return;
144+
this.fileLoggingDisabled = true;
145+
146+
const label = this.config.name ? `[${this.config.name}] ` : '';
147+
const notice = `${label}logger: file logging disabled — cannot write to ${path}: ${reason}`;
148+
if (typeof process !== 'undefined' && (process as any).stderr) {
149+
(process as any).stderr.write(notice + '\n');
150+
} else if (typeof console !== 'undefined') {
151+
console.warn(notice);
82152
}
83153
}
84154

@@ -197,8 +267,12 @@ export class ObjectLogger implements Logger {
197267
}
198268

199269
child(context: Record<string, any>): ObjectLogger {
200-
const child = new ObjectLogger(this.config, { ...this.bindings, ...context });
201-
// Share the file stream — no double-open
270+
// Construct without `file`, then share the parent's stream: the
271+
// constructor opens eagerly, so passing `file` through would open a
272+
// second stream per child and immediately orphan it. That leak was
273+
// unreachable while #3110 kept the ESM open path dead.
274+
const child = new ObjectLogger({ ...this.config, file: undefined }, { ...this.bindings, ...context });
275+
child.config.file = this.config.file;
202276
child.fileStream = this.fileStream;
203277
return child;
204278
}
@@ -208,10 +282,15 @@ export class ObjectLogger implements Logger {
208282
}
209283

210284
async destroy(): Promise<void> {
211-
if (this.fileStream) {
212-
await new Promise<void>((resolve) => this.fileStream.end(resolve));
213-
this.fileStream = undefined;
214-
}
285+
const stream = this.fileStream;
286+
this.fileStream = undefined;
287+
// Children share the opener's stream; if they closed it too, one child's
288+
// teardown would end file logging for the parent and every sibling,
289+
// whose writes then land on a closed stream and only trip the 'error'
290+
// handler above.
291+
if (!stream || !this.ownsFileStream) return;
292+
this.ownsFileStream = false;
293+
await new Promise<void>((resolve) => stream.end(resolve));
215294
}
216295
}
217296

pnpm-lock.yaml

Lines changed: 3 additions & 0 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

0 commit comments

Comments
 (0)