From 521369e02fb7e50a4be080357ccef555f5e9ec89 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 07:18:35 -0600 Subject: [PATCH] fix(logging): stop the no-config window dropping every log line MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit initLogSettings() falls back to a no-config branch on any host without a harperdb-config.yaml — the install window, and a fresh CI runner. It sets `log_to_file = false; logToStdstreams = true`, which reads as "the streams are the sink now", and then called createLogger() without passing stdStreams. createLogger destructures that option into a local of the same name, which shadows the module-level flag inside logStdOut/logStdErr, so the branch wrote nowhere at all: before a config exists, every log line Harper produced was silently dropped, install errors included. That branch also returns before the stdioLogging() call at the end of initLogSettings(), so the streams it now writes to would have had no EPIPE/EIO listener — `harper install | head -1` closes the reader, and the async error would land on a stream with none and take the install down. Install the guards there too; their write override is inert on this branch, because log_to_file is false. Found from the Windows unit gate, where the guard's warn-cadence case counted 0 of 2 warnings (harper#2364). #2468 has since made that harness bring its own config, which is the right fix for the test; this is the product bug underneath it, which that leaves in place. A child-process case pins both halves: it spawns with ROOTPATH at a directory holding no config, which reaches the fallback on an installed machine and a bare one alike, and asserts the warning on stderr and the guard listener on each stream. It fails on the old createLogger() call, and again without the stdioLogging() call. Verified: `npm run test:unit:windows` (the Windows gate's own groups, on Linux). Refs #2364 Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_017gPFHKnh2qasUuy53fdzbe --- .../logging/fixtures/noConfigLogging.cjs | 15 ++++++++ .../utility/logging/harper_logger.test.js | 37 ++++++++++++++++++- utility/logging/harper_logger.ts | 9 ++++- 3 files changed, 59 insertions(+), 2 deletions(-) create mode 100644 unitTests/utility/logging/fixtures/noConfigLogging.cjs diff --git a/unitTests/utility/logging/fixtures/noConfigLogging.cjs b/unitTests/utility/logging/fixtures/noConfigLogging.cjs new file mode 100644 index 0000000000..0e111ae338 --- /dev/null +++ b/unitTests/utility/logging/fixtures/noConfigLogging.cjs @@ -0,0 +1,15 @@ +'use strict'; + +// The no-config logging window — install, and any host with no harperdb-config.yaml. +// initLogSettings() picks that branch at module load, from the machine's own config resolution, +// which is why this is a child: the caller spawns it with ROOTPATH at a directory holding no +// config, and the branch is then taken on an installed machine and a bare one alike. + +const { warn } = require('#src/utility/logging/harper_logger'); + +warn('no-config stream check'); + +// stdioLogging() stashes its 'error' listener on the stream it guards, and the fallback branch +// returns before the call at the end of initLogSettings(). +const guarded = (stream) => typeof stream.harperStdioErrorHandler === 'function'; +process.stdout.write(`stdout-guard=${guarded(process.stdout)} stderr-guard=${guarded(process.stderr)}\n`); diff --git a/unitTests/utility/logging/harper_logger.test.js b/unitTests/utility/logging/harper_logger.test.js index f6254c7d73..08603408c4 100644 --- a/unitTests/utility/logging/harper_logger.test.js +++ b/unitTests/utility/logging/harper_logger.test.js @@ -1,7 +1,8 @@ 'use strict'; const assert = require('node:assert'); -const { EventEmitter } = require('node:events'); +const { EventEmitter, once } = require('node:events'); +const { spawn } = require('node:child_process'); const sinon = require('sinon'); const chai = require('chai'); const expect = chai.expect; @@ -192,6 +193,40 @@ describe('Test harper_logger module', () => { expect(log_file_path).to.eql(path.join(TEST_LOG_DIR, 'hdb.log')); }); + // The install window, and any host with no harperdb-config.yaml. `log_to_file` is false + // there, so the streams are the only sink left; createLogger() shadows the module-level + // `logToStdstreams` with its own option, and a call that omits it drops the line entirely + // rather than writing it anywhere (harper#2364, where the Windows gate caught it as a + // warning-cadence test counting 0 of 2). + it('writes to the std streams, guarded, when there is no config to read', async function () { + this.timeout(30000); + const noConfigRoot = fs.mkdtempSync(path.join(os.tmpdir(), 'harper-no-config-')); + afterThisTest.push(() => { + try { + fs.removeSync(noConfigRoot); + } catch {} + }); + + // A ROOTPATH naming a directory with no config reaches the fallback either way: with boot + // properties present the config read throws ENOENT, and without them initLogSettings() + // only swallows that failure when ROOTPATH *does* hold a config. LOGGING_LEVEL is pinned + // for the same reason — that branch reads it from the environment, and the fixture logs + // at the default threshold. + const child = spawn(process.execPath, [require.resolve('./fixtures/noConfigLogging.cjs')], { + stdio: ['ignore', 'pipe', 'pipe'], + env: { ...process.env, ROOTPATH: noConfigRoot, LOGGING_LEVEL: 'warn' }, + }); + let stdout = ''; + let stderr = ''; + child.stdout.on('data', (chunk) => (stdout += chunk)); + child.stderr.on('data', (chunk) => (stderr += chunk)); + const [code] = await once(child, 'close'); + + assert.equal(code, 0, `fixture exited ${code}: ${stderr}`); + assert.match(stderr, /no-config stream check/); + assert.match(stdout, /stdout-guard=true stderr-guard=true/); + }); + it('Test that if error code is not ENOENT error is handled correctly', () => { // This asserts the path where there is nothing to fall back to, so ROOTPATH has to be // absent: initLogSettings() deliberately SWALLOWS a failure to read the boot properties diff --git a/utility/logging/harper_logger.ts b/utility/logging/harper_logger.ts index 87e14d5cff..db6206afbd 100644 --- a/utility/logging/harper_logger.ts +++ b/utility/logging/harper_logger.ts @@ -545,10 +545,17 @@ export function initLogSettings(forceInit = false) { logLevel = logLevel === undefined ? defaultLevel : logLevel; - mainLogger = createLogger({ level: logLevel }); + // createLogger shadows the module-level `logToStdstreams` with this option, so omitting it + // drops every log written before a config exists rather than routing it to the streams. + mainLogger = createLogger({ level: logLevel, stdStreams: logToStdstreams }); // setup the external logger externalLogger = mainLogger.forComponent('external'); externalLogger.tag = null; // don't tag by default + // The streams are this branch's only sink, so it needs the same EPIPE/EIO listeners the + // configured path installs below: `harper install | head -1` closes the reader, and the + // async error would otherwise land on a stream with none and take the install down. The + // guard's write override is inert here, because `log_to_file` is false. + stdioLogging(); return; }