Skip to content

Commit 2a356c3

Browse files
authored
fix(core): respect log level in worker threads (#1058)
* fix(core): respect log level in worker threads The log level set by `--log-level` was only applied on the main thread. Worker threads load their own module graph, so the default logger export creates a separate instance there that keeps the default `info` level. Warnings emitted from inside workers were therefore printed regardless of the requested level. Pass the level through Piscina `workerData` and apply it at the worker entry point. This adds a `getLogLevel()` accessor, as there was no way to read the configured level back. Fixes: #1032 Signed-off-by: Avocado <ujubongbong@gmail.com> * test(core): cover log level propagation to workers Assert that the pool forwards the current level through `workerData` and that a worker actually applies it, using a fixture generator that reports the level it sees. Removing the fix makes both fail, while the default level case keeps passing. Also cover the new `getLogLevel()` accessor. Signed-off-by: Avocado <ujubongbong@gmail.com> --------- Signed-off-by: Avocado <ujubongbong@gmail.com>
1 parent 91c9fc6 commit 2a356c3

7 files changed

Lines changed: 154 additions & 0 deletions

File tree

‎.changeset/worker-log-level.md‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
---
2+
'@doc-kit/core': patch
3+
---
4+
5+
fix: respect `--log-level` in worker threads

‎packages/core/src/logger/__tests__/logger.test.mjs‎

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -380,4 +380,35 @@ describe('createLogger', () => {
380380
strictEqual(transport.mock.callCount(), 1); // Debug should be filtered
381381
});
382382
});
383+
384+
describe('getLogLevel', () => {
385+
it('should return the level the logger was created with', t => {
386+
const logger = createLogger(t.mock.fn(), LogLevel.warn);
387+
388+
strictEqual(logger.getLogLevel(), LogLevel.warn);
389+
});
390+
391+
it('should default to info when no level is given', t => {
392+
const logger = createLogger(t.mock.fn());
393+
394+
strictEqual(logger.getLogLevel(), LogLevel.info);
395+
});
396+
397+
it('should reflect a level set afterwards', t => {
398+
const logger = createLogger(t.mock.fn(), LogLevel.info);
399+
400+
logger.setLogLevel('fatal');
401+
402+
strictEqual(logger.getLogLevel(), LogLevel.fatal);
403+
});
404+
405+
it('should reflect the propagated level on children', t => {
406+
const logger = createLogger(t.mock.fn(), LogLevel.info);
407+
const child = logger.child('module');
408+
409+
logger.setLogLevel(LogLevel.error);
410+
411+
strictEqual(child.getLogLevel(), LogLevel.error);
412+
});
413+
});
383414
});

‎packages/core/src/logger/logger.mjs‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -165,6 +165,13 @@ export const createLogger = (
165165
}
166166
};
167167

168+
/**
169+
* Gets the current log level for this logger instance.
170+
*
171+
* @returns {number} The current numeric log level
172+
*/
173+
const getLogLevel = () => currentLevel;
174+
168175
return {
169176
info,
170177
warn,
@@ -173,5 +180,6 @@ export const createLogger = (
173180
debug,
174181
child,
175182
setLogLevel,
183+
getLogLevel,
176184
};
177185
};
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
import logger from '#logger/index.mjs';
2+
3+
/**
4+
* Test generator that reports the log level seen inside the worker, so the
5+
* propagation of the level across the thread boundary can be asserted.
6+
*
7+
* @type {GeneratorMetadata<unknown, number[]>}
8+
*/
9+
export default {
10+
name: 'log-level-reporter',
11+
version: '1.0.0',
12+
description: 'Reports the log level active inside the worker',
13+
dependsOn: 'ast',
14+
processChunk: async (_input, itemIndices) =>
15+
itemIndices.map(() => logger.getLogLevel()),
16+
async generate() {
17+
return [logger.getLogLevel()];
18+
},
19+
};
Lines changed: 83 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,83 @@
1+
import { strictEqual } from 'node:assert';
2+
import { describe, it } from 'node:test';
3+
import { fileURLToPath } from 'node:url';
4+
5+
import { LogLevel } from '../../logger/constants.mjs';
6+
import logger from '../../logger/index.mjs';
7+
import createWorkerPool from '../index.mjs';
8+
9+
const reporterSpecifier = fileURLToPath(
10+
import.meta.resolve('./fixtures/log-level-reporter.mjs')
11+
);
12+
13+
/**
14+
* Runs a function with the logger temporarily set to the given level.
15+
*
16+
* @template T
17+
* @param {number} level - Log level to apply for the duration of the callback
18+
* @param {() => Promise<T>} fn - Callback to run
19+
* @returns {Promise<T>}
20+
*/
21+
const withLogLevel = async (level, fn) => {
22+
const original = logger.getLogLevel();
23+
24+
logger.setLogLevel(level);
25+
26+
try {
27+
return await fn();
28+
} finally {
29+
logger.setLogLevel(original);
30+
}
31+
};
32+
33+
describe('createWorkerPool', () => {
34+
it('should forward the current log level to workers', async () => {
35+
await withLogLevel(LogLevel.fatal, async () => {
36+
const pool = createWorkerPool(1);
37+
38+
try {
39+
strictEqual(pool.options.workerData.logLevel, LogLevel.fatal);
40+
} finally {
41+
await pool.destroy();
42+
}
43+
});
44+
});
45+
46+
it('should apply the forwarded log level inside the worker', async () => {
47+
await withLogLevel(LogLevel.fatal, async () => {
48+
const pool = createWorkerPool(1);
49+
50+
try {
51+
const [levelInWorker] = await pool.run({
52+
generatorSpecifier: reporterSpecifier,
53+
input: [null],
54+
itemIndices: [0],
55+
extra: {},
56+
configuration: {},
57+
});
58+
59+
strictEqual(levelInWorker, LogLevel.fatal);
60+
} finally {
61+
await pool.destroy();
62+
}
63+
});
64+
});
65+
66+
it('should leave workers at the default level when it is not changed', async () => {
67+
const pool = createWorkerPool(1);
68+
69+
try {
70+
const [levelInWorker] = await pool.run({
71+
generatorSpecifier: reporterSpecifier,
72+
input: [null],
73+
itemIndices: [0],
74+
extra: {},
75+
configuration: {},
76+
});
77+
78+
strictEqual(levelInWorker, LogLevel.info);
79+
} finally {
80+
await pool.destroy();
81+
}
82+
});
83+
});

‎packages/core/src/threading/chunk-worker.mjs‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,13 @@
1+
import { workerData } from 'node:worker_threads';
2+
13
import { loadGenerator } from '#generators/loader.mjs';
4+
import logger from '#logger/index.mjs';
25
import { setConfig } from '#utils/configuration/index.mjs';
36

7+
if (workerData?.logLevel !== undefined) {
8+
logger.setLogLevel(workerData.logLevel);
9+
}
10+
411
/**
512
* Processes a chunk of items using the specified generator's processChunk method.
613
* This is the worker entry point for Piscina.

‎packages/core/src/threading/index.mjs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,5 +23,6 @@ export default function createWorkerPool(threads) {
2323
minThreads: 0,
2424
maxThreads: threads,
2525
idleTimeout: 1_000,
26+
workerData: { logLevel: logger.getLogLevel() },
2627
});
2728
}

0 commit comments

Comments
 (0)