diff --git a/DESIGN.md b/DESIGN.md index 243c906dca..e002f9a761 100644 --- a/DESIGN.md +++ b/DESIGN.md @@ -189,6 +189,7 @@ Index of the design notes for the harper core: one line per note, grouped by the - [Every path handed to a native file watch must be canonicalized (`utility/watchPath.ts`)](utility/DESIGN.md#every-path-handed-to-a-native-file-watch-must-be-canonicalized-utilitywatchpathts) — Every native file-watch path is canonicalized first: libuv aborts the process on a Windows 8.3 short-path mismatch. - [Interactive CLI prompts go through `utility/interactivePrompts.ts`](utility/DESIGN.md#interactive-cli-prompts-go-through-utilityinteractivepromptsts) — Every `@inquirer` prompt uses this seam, which lazy-loads packages off the boot path, exits 130 on Ctrl-C and gives tests a stubbable raw layer. - [An HdbError's `message` is a string; the structured body is `http_resp_msg` (`utility/errors/hdbError.ts`)](utility/DESIGN.md#an-hdberrors-message-is-a-string-the-structured-body-is-http_resp_msg-utilityerrorshdberrorts) — A report object passed to `handleHDBError` is the response body and the job message; `message` is a string derived from it. +- [Log-file identity is compared as BigInt (`utility/logging/logGenerationCoordinator.ts` `FileIdentity`)](utility/DESIGN.md#log-file-identity-is-compared-as-bigint-utilityloggingloggenerationcoordinatorts-fileidentity) — A Number rounds 64-bit Windows file IDs past 2^53, making neighbouring files look identical. ## build-tools/ — packaging and published artifacts diff --git a/unitTests/utility/logging/fixtures/highFileIdLogging.cjs b/unitTests/utility/logging/fixtures/highFileIdLogging.cjs new file mode 100644 index 0000000000..5c1c3d12e8 --- /dev/null +++ b/unitTests/utility/logging/fixtures/highFileIdLogging.cjs @@ -0,0 +1,157 @@ +'use strict'; + +// Log-generation identity on a volume whose 64-bit file IDs are past 2^53 — NTFS, once an MFT record +// has been reused 32 times — where a Number stat rounds neighbouring files to one value. Each file +// here reports 2^70 plus its own small index: distinct as BigInt, a single value as a Number. +// Installed before anything loads fs, so graceful-fs and the ESM bindings of node:fs see it too. Only +// the synchronous stats are emulated, because every log identity read is synchronous. +const fs = require('node:fs'); +const HIGH_FILE_ID = 2n ** 70n; +const fileIndexes = new Map(); +const statsByPath = new Map(); +for (const name of ['statSync', 'fstatSync', 'lstatSync']) { + const original = fs[name]; + fs[name] = (...args) => { + if (typeof args[0] === 'string') statsByPath.set(args[0], (statsByPath.get(args[0]) ?? 0) + 1); + const stats = original(...args); + if (stats?.ino) { + const realId = BigInt(stats.ino); + if (!fileIndexes.has(realId)) fileIndexes.set(realId, BigInt(fileIndexes.size + 1)); + const ino = HIGH_FILE_ID + fileIndexes.get(realId); + stats.ino = typeof stats.ino === 'bigint' ? ino : Number(ino); + } + return stats; + }; +} +require('node:module').syncBuiltinESMExports(); + +const assert = require('node:assert'); +const path = require('node:path'); +const { setTimeout: sleep } = require('node:timers/promises'); +const { pinLogConfig } = require('../../../logConfigFixture.js'); +const { waitFor } = require('../../../waitFor.js'); + +const hdbLogger = require('#src/utility/logging/harper_logger'); +const { requestStaleDescriptorRelease } = require('#src/utility/logging/logGenerationCoordinator'); +// Before the log config is pinned: its environmentManager validates the inherited ROOTPATH's full config. +const { logRotator } = require('#src/utility/logging/logRotator'); + +const NEVER_TICKS = 3600000; +const root = process.argv[2]; +const restoreLogConfig = pinLogConfig({ level: 'error' }); + +function newLogger(name, rotation) { + const logPath = path.join(root, name, 'hdb.log'); + fs.mkdirSync(path.dirname(logPath), { recursive: true }); + const logger = hdbLogger.createLogger({ stdStreams: false, path: logPath, level: 'error', rotation }); + return { logger, logPath }; +} + +function replaceUnderLogger(logPath, archivePath = `${logPath}.archived`) { + fs.renameSync(logPath, archivePath); + fs.writeFileSync(logPath, 'replacement generation\n'); + const exact = [archivePath, logPath].map((file) => fs.statSync(file, { bigint: true }).ino); + const rounded = [archivePath, logPath].map((file) => fs.statSync(file).ino); + assert.notStrictEqual(exact[0], exact[1], 'the emulated file IDs must stay distinct as BigInt'); + assert.strictEqual(rounded[0], rounded[1], 'the emulated file IDs must collide as Numbers'); + return archivePath; +} + +async function untilStatted(file, count) { + const target = (statsByPath.get(file) ?? 0) + count; + for (let polls = 0; (statsByPath.get(file) ?? 0) < target; polls++) { + if (polls === 1000) throw new Error(`${file} was statted fewer than ${count} times in 10s`); + await sleep(10); + } +} + +function contains(file, marker) { + return fs.readFileSync(file, 'utf8').includes(marker); +} + +async function assertWrittenToLiveFile(logPath, archivePath, marker) { + await waitFor(() => contains(logPath, marker) || contains(archivePath, marker), { + timeout: 10000, + message: `${marker} was never written`, + }); + assert.ok(contains(logPath, marker), `${marker} was appended to the archived generation`); +} + +async function staleSweepReleasesTheArchivedGeneration() { + const { logger, logPath } = newLogger('staleSweep'); + logger.error('opens the descriptor'); + const archivePath = replaceUnderLogger(logPath); + assert.ok((await requestStaleDescriptorRelease()).released); + logger.error('after the stale sweep'); + await assertWrittenToLiveFile(logPath, archivePath, 'after the stale sweep'); +} + +async function writePathGuardNoticesTheReplacement() { + const { logger, logPath } = newLogger('writePath', { + enabled: true, + maxSize: '16K', + auditInterval: NEVER_TICKS, + path: path.join(root, 'writePath', 'rotated'), + }); + logger.error('opens the descriptor'); + const archivePath = replaceUnderLogger(logPath); + // The guard checks after each 1000-byte quantum, and the append that crosses it lands first, so + // only what is written after the filler has flushed must reach the live file. + for (let i = 0; i < 40; i++) logger.error(`filler ${i} ${'x'.repeat(60)}`); + await waitFor(() => contains(logPath, 'filler 39 ') || contains(archivePath, 'filler 39 '), { + timeout: 10000, + message: 'the filler was never written', + }); + logger.error('after the checkpoint'); + await assertWrittenToLiveFile(logPath, archivePath, 'after the checkpoint'); +} + +async function intervalClockSeesTheReplacement() { + const intervalMs = 60000; + const { logger, logPath } = newLogger('intervalClock'); + logger.error('first generation'); + const rotatedDir = path.join(root, 'intervalClock', 'rotated'); + // Time passes only when this scenario advances it, while the audit ticks stay on real timers, so a + // late tick can postpone a rotation and never cause one. + const realNow = Date.now; + let now = realNow(); + Date.now = () => now; + try { + const rotator = logRotator({ + logger, + path: rotatedDir, + enabled: true, + compress: false, + auditInterval: 20, + interval: `${intervalMs / 1000}s`, + }); + now += intervalMs / 2; + logger.closeLogFile(); + replaceUnderLogger(logPath, path.join(rotatedDir, 'replaced-by-writer.log')); + // Past the first generation's interval and short of the replacement's. + now += intervalMs / 2 + 1000; + // A tick stats the log once, or twice when it rotates, and ticks never overlap, so a third stat + // means the first tick on the advanced clock has finished. + await untilStatted(logPath, 3); + rotator.end(); + assert.strictEqual(rotator.getLastRotatedLogPath(), undefined, 'the replacement was rotated as if it were old'); + } finally { + Date.now = realNow; + } +} + +(async () => { + await staleSweepReleasesTheArchivedGeneration(); + await writePathGuardNoticesTheReplacement(); + await intervalClockSeesTheReplacement(); +})().then( + () => { + restoreLogConfig(); + process.exit(0); + }, + (error) => { + restoreLogConfig(); + process.stderr.write(`${error.stack}\n`); + process.exit(1); + } +); diff --git a/unitTests/utility/logging/logFileIdentity.test.js b/unitTests/utility/logging/logFileIdentity.test.js new file mode 100644 index 0000000000..9a5d44fb26 --- /dev/null +++ b/unitTests/utility/logging/logFileIdentity.test.js @@ -0,0 +1,26 @@ +'use strict'; + +const assert = require('node:assert'); +const fs = require('fs-extra'); +const path = require('node:path'); +const { spawnSync } = require('node:child_process'); + +const TEST_ROOT = path.join(__dirname, 'fileIdentityLogs'); + +describe('Log generation identity on a volume with file IDs past 2^53', () => { + after(() => { + try { + fs.removeSync(TEST_ROOT); + } catch {} + }); + + // A child process: the emulated file IDs have to be in place before anything loads fs. + it('tells neighbouring files apart in the stale sweep, the write-path guard and the interval clock', () => { + fs.mkdirpSync(TEST_ROOT); + const child = spawnSync(process.execPath, [path.join(__dirname, 'fixtures', 'highFileIdLogging.cjs'), TEST_ROOT], { + encoding: 'utf8', + timeout: 60000, + }); + assert.strictEqual(child.status, 0, `exit ${child.status} ${child.signal ?? ''}\n${child.stdout}\n${child.stderr}`); + }).timeout(70000); +}); diff --git a/unitTests/utility/logging/logGenerationCoordinator.test.js b/unitTests/utility/logging/logGenerationCoordinator.test.js index ca1052afae..526bfaa8d3 100644 --- a/unitTests/utility/logging/logGenerationCoordinator.test.js +++ b/unitTests/utility/logging/logGenerationCoordinator.test.js @@ -159,7 +159,7 @@ describe('Test log generation coordinator (#1877)', () => { fs.mkdirpSync(dir); const logPath = path.join(dir, 'hdb.log'); fs.writeFileSync(logPath, 'held\n'); - const held = fs.statSync(logPath); + const held = fs.statSync(logPath, { bigint: true }); let closed = 0; coordinator.registerLogSink(logPath, { identity: () => ({ ino: held.ino, dev: held.dev }), @@ -168,12 +168,12 @@ describe('Test log generation coordinator (#1877)', () => { transport.deliverRotation({ logPath, request: 'g', ino: held.ino, dev: held.dev, originator: 0 }); assert.strictEqual(closed, 1, 'expected the sink to be asked to close its descriptor'); // A generation this sink never held must not close anything. - transport.deliverRotation({ logPath, request: 'g2', ino: held.ino + 1, dev: held.dev, originator: 0 }); + transport.deliverRotation({ logPath, request: 'g2', ino: held.ino + 1n, dev: held.dev, originator: 0 }); assert.strictEqual(closed, 1, 'expected a foreign generation to leave the descriptor alone'); coordinator.unregisterLogSink(logPath); // The per-generation release needs the same fail-closed treatment as the stale sweep below. - coordinator.registerLogSink(logPath, { identity: () => ({ ino: 0, dev: 0 }), close: () => closed++ }); + coordinator.registerLogSink(logPath, { identity: () => ({ ino: 0n, dev: 0n }), close: () => closed++ }); transport.deliverRotation({ logPath, request: 'g3', ino: held.ino, dev: held.dev, originator: 0 }); assert.strictEqual(closed, 2, 'expected an indistinguishable announced generation to be released'); coordinator.unregisterLogSink(logPath); @@ -188,7 +188,7 @@ describe('Test log generation coordinator (#1877)', () => { assert.strictEqual(closed, 2, 'expected the live generation to be kept'); coordinator.unregisterLogSink(logPath); coordinator.registerLogSink(logPath, { - identity: () => ({ ino: held.ino + 1, dev: held.dev }), + identity: () => ({ ino: held.ino + 1n, dev: held.dev }), close: () => closed++, }); transport.deliverRotation({ request: 'r2', stale: true }); @@ -197,7 +197,7 @@ describe('Test log generation coordinator (#1877)', () => { // A filesystem that reports ino 0 cannot prove a descriptor is on the live generation, and // answering "released" without releasing is what lets an archive be destroyed under a peer. - coordinator.registerLogSink(logPath, { identity: () => ({ ino: 0, dev: 0 }), close: () => closed++ }); + coordinator.registerLogSink(logPath, { identity: () => ({ ino: 0n, dev: 0n }), close: () => closed++ }); transport.deliverRotation({ request: 'r3', stale: true }); assert.strictEqual(closed, 4, 'expected an indistinguishable descriptor to be released'); coordinator.unregisterLogSink(logPath); @@ -221,10 +221,10 @@ describe('Test log generation coordinator (#1877)', () => { for (const name of ['hdb.log', 'component.log', 'external.log']) { const logPath = path.join(dir, name); fs.writeFileSync(logPath, `${name} contents\n`); - held[name] = fs.statSync(logPath); + held[name] = fs.statSync(logPath, { bigint: true }); coordinator.registerLogSink(logPath, { // hdb.log is on its live generation; the other two hold an older inode. - identity: () => (name === 'hdb.log' ? held[name] : { ino: held[name].ino + 1000, dev: held[name].dev }), + identity: () => (name === 'hdb.log' ? held[name] : { ino: held[name].ino + 1000n, dev: held[name].dev }), close: () => closed.push(name), }); } @@ -265,8 +265,8 @@ describe('Test log generation coordinator (#1877)', () => { fs.mkdirpSync(dir); const logPath = path.join(dir, 'hdb.log'); fs.writeFileSync(logPath, 'contents\n'); - const held = fs.statSync(logPath); - const stale = { ino: held.ino + 1000, dev: held.dev }; + const held = fs.statSync(logPath, { bigint: true }); + const stale = { ino: held.ino + 1000n, dev: held.dev }; const closed = []; const first = { identity: () => stale, close: () => closed.push('first') }; const second = { identity: () => stale, close: () => closed.push('second') }; diff --git a/unitTests/utility/logging/logRotationGuard.test.js b/unitTests/utility/logging/logRotationGuard.test.js index d5b0052fe3..5ab9d29e52 100644 --- a/unitTests/utility/logging/logRotationGuard.test.js +++ b/unitTests/utility/logging/logRotationGuard.test.js @@ -7,7 +7,7 @@ const { spawnSync } = require('node:child_process'); const { Worker } = require('node:worker_threads'); const hdbTerms = require('#src/utility/hdbTerms'); const hdbLogger = require('#src/utility/logging/harper_logger'); -const { parseMaxSize } = require('#src/utility/logging/logRotation'); +const { parseMaxSize, rotateLogFileSync } = require('#src/utility/logging/logRotation'); const { requestGenerationClose } = require('#src/utility/logging/logGenerationCoordinator'); const { pinLogConfig } = require('../../logConfigFixture.js'); const { waitFor } = require('../../waitFor.js'); @@ -304,12 +304,14 @@ describe('Test log rotation on the write path (#1877)', () => { rotation: { enabled: true, interval: '1D', auditInterval: NEVER_TICKS }, }); logger.error('opens the descriptor'); - const held = fs.statSync(logPath); - // Another thread rotates: the file moves out from under this descriptor. - const archivePath = path.join(dir, 'moved.log'); - fs.renameSync(logPath, archivePath); - await requestGenerationClose({ logPath, generation: 'g', ino: held.ino, dev: held.dev }); + // Another thread rotates: the file moves out from under this descriptor. The announcement carries + // the identity that rotation read, so it has to match the one this sink read when it opened. + const rotatedDir = path.join(dir, 'rotated'); + fs.mkdirpSync(rotatedDir); + const generation = rotateLogFileSync(logPath, rotatedDir, () => {}); + const { archivePath } = generation; + await requestGenerationClose(generation); const marker = 'after the announced rotation'; logger.error(marker); diff --git a/utility/DESIGN.md b/utility/DESIGN.md index b1cd140295..d940287ddb 100644 --- a/utility/DESIGN.md +++ b/utility/DESIGN.md @@ -2,7 +2,7 @@ Cross-cutting helpers. -**Read this when:** touching `watchPath.ts` or anything that arms a native file watch, adding an interactive CLI prompt (`interactivePrompts.ts`), or passing an object to `handleHDBError` (`errors/hdbError.ts`). +**Read this when:** touching `watchPath.ts` or anything that arms a native file watch, adding an interactive CLI prompt (`interactivePrompts.ts`), passing an object to `handleHDBError` (`errors/hdbError.ts`), or comparing which file a log descriptor is on (`logging/`). Index of every design note: [DESIGN.md](../DESIGN.md). @@ -61,3 +61,7 @@ Every `@inquirer`-based one-shot prompt in the codebase (`bin/login.ts`, `bin/de ## An HdbError's `message` is a string; the structured body is `http_resp_msg` (`utility/errors/hdbError.ts`) `handleHDBError(new Error(), , status)` is how a permission report or validation report becomes an error: the object is the response body. `serverErrorHandler` sends an object `http_resp_msg` verbatim, and the job worker (`server/jobs/jobProcess.ts`) records it as the job's `message`, which is what `get_job` answers a refused bulk load with. The constructor derives `message` from it — the `error` summary followed by the reasons the object lists, anything else through `inspectForLog`, which cannot throw and does not expose a nested Error's properties — because the logger, `String(error)` and `errorToString` (HTTP error bodies, replication replies) all need a string. A non-string `message` rendered as `Error: [object Object]`. Read the structure from `http_resp_msg`, never from `message`. + +## Log-file identity is compared as BigInt (`utility/logging/logGenerationCoordinator.ts` `FileIdentity`) + +Every `(dev, ino)` log rotation compares is read with `{ bigint: true }`: Windows reports a 64-bit file ID, and past 2^53 a Number rounds neighbouring files to one value, so a descriptor on an archived generation passes as live. Enforced by the `FileIdentity` type on every identity producer and on the coordinator's sink and announcement API, and by `unitTests/utility/logging/logFileIdentity.test.js`, which emulates such a volume. diff --git a/utility/logging/harper_logger.ts b/utility/logging/harper_logger.ts index 4c345573b8..716c0ff99e 100644 --- a/utility/logging/harper_logger.ts +++ b/utility/logging/harper_logger.ts @@ -14,7 +14,7 @@ import { _assignPackageExport } from '../../globals.js'; import { Console } from 'console'; import { inspect, types } from 'node:util'; import { createRotationGuard, INVALID_MAX_SIZE_MSG, parseMaxSize, resolveRotatedLogDir } from './logRotation.ts'; -import { registerLogSink } from './logGenerationCoordinator.ts'; +import { type FileIdentity, registerLogSink } from './logGenerationCoordinator.ts'; const { isNativeError } = types; // store the native write function so we can call it after we write to the log file (and store it on process.stdout @@ -869,8 +869,8 @@ function getFileLogger(path, rotation, isExternalInstance, rotationPolicy) { let rotationProblemNotice; let logTimeUsage = 0; let rotationGuard, - logFDIdentity, nextRotationReport = 0; + let logFDIdentity: FileIdentity | null; if (!logger) { logger = logToFile; logger.closeLogFile = closeLogFile; @@ -1053,7 +1053,7 @@ function getFileLogger(path, rotation, isExternalInstance, rotationPolicy) { // Which generation this descriptor belongs to, recorded once here so the size guard's // checkpoint needs a single pathname stat to tell whether the file has moved under it. try { - const opened = fs.fstatSync(logFD); + const opened = fs.fstatSync(logFD, { bigint: true }); logFDIdentity = { ino: opened.ino, dev: opened.dev }; } catch { logFDIdentity = null; diff --git a/utility/logging/logGenerationCoordinator.ts b/utility/logging/logGenerationCoordinator.ts index 4b9ff670a1..d7a2dd24eb 100644 --- a/utility/logging/logGenerationCoordinator.ts +++ b/utility/logging/logGenerationCoordinator.ts @@ -31,7 +31,12 @@ interface RotationTransport { } let transport: RotationTransport | undefined; -type LogSink = { identity(): any; close(): void }; +/** + * Which file a descriptor or pathname is on. Read with `{ bigint: true }`: Windows reports a 64-bit file + * ID, and past 2^53 a Number rounds two neighbouring files to the same value. + */ +export type FileIdentity = { ino: bigint; dev: bigint }; +type LogSink = { identity(): FileIdentity | null; close(): void }; // A set per path, not one sink: harper_logger caches its file loggers by the raw configured path, so // two spellings of one file are two sinks holding two descriptors on it, and a release has to close // both. The key is resolved because retention compares resolved paths. @@ -125,7 +130,10 @@ function requestRelease(message: any, deadline?: number): Promise<{ released: bo } /** One archived generation: release any descriptor still pointing at the inode that was renamed. */ -export async function requestGenerationClose(generation: any, deadline?: number): Promise { +export async function requestGenerationClose( + generation: FileIdentity & { generation: string; logPath: string }, + deadline?: number +): Promise { return ( await requestRelease( { @@ -178,7 +186,7 @@ function releaseStaleDescriptors() { for (const [logPath, sinks] of sinksByPath) { let live; try { - live = statSync(logPath); + live = statSync(logPath, { bigint: true }); } catch { for (const sink of sinks) sink.close(); continue; diff --git a/utility/logging/logRotation.ts b/utility/logging/logRotation.ts index a25410c926..f99f22844e 100644 --- a/utility/logging/logRotation.ts +++ b/utility/logging/logRotation.ts @@ -6,6 +6,7 @@ // guard installed on a timer is a guard the first megabytes of a burst are written without. import { + type BigIntStats, createReadStream, createWriteStream, existsSync, @@ -19,7 +20,7 @@ import { pipeline } from 'node:stream/promises'; import { basename, dirname, extname, join, resolve } from 'node:path'; import { createHash } from 'node:crypto'; import { isMainThread, threadId } from 'node:worker_threads'; -import { nextGenerationId, requestGenerationClose } from './logGenerationCoordinator.ts'; +import { type FileIdentity, nextGenerationId, requestGenerationClose } from './logGenerationCoordinator.ts'; // Bounds each writer's blind window at one quantum plus the flush that crosses it, so the file is // bounded by maxBytes + T * (quantum + batch) rather than by elapsed time. Fixed, not a remaining @@ -80,8 +81,13 @@ export function archivePathFor(logPath: string, rotatedLogDir: string) { * a rotation that yields to the event loop lets the logging loop that triggered it keep appending, * which is the rate-dependent overshoot this whole change exists to remove. */ -export function rotateLogFileSync(logPath: string, rotatedLogDir: string, closeLogFile: () => void, activeStats?: any) { - const active = activeStats ?? statSync(logPath); +export function rotateLogFileSync( + logPath: string, + rotatedLogDir: string, + closeLogFile: () => void, + activeStats?: BigIntStats +) { + const active = activeStats ?? statSync(logPath, { bigint: true }); const archivePath = archivePathFor(logPath, rotatedLogDir); renameSync(logPath, archivePath); closeLogFile(); @@ -91,7 +97,7 @@ export function rotateLogFileSync(logPath: string, rotatedLogDir: string, closeL // peer would answer "released" while still appending to the one about to be destroyed. let { ino, dev } = active; try { - ({ ino, dev } = statSync(archivePath)); + ({ ino, dev } = statSync(archivePath, { bigint: true })); } catch { // Already claimed by retention or another pass; the pre-rename identity is the best available. } @@ -103,7 +109,7 @@ export function rotateLogFileSync(logPath: string, rotatedLogDir: string, closeL * it if requested. The plain archive is only unlinked once that release is proven. */ export async function publishArchivedGeneration( - generation: any, + generation: ReturnType, compress?: boolean, reportCompressionError?: (error: any) => void ) { @@ -243,7 +249,16 @@ async function compressOneArchive(archivePath: string) { * The write-path size guard. One subtraction and one branch per flush; one pathname stat once per * quantum of this writer's own output. */ -export function createRotationGuard(options: any) { +export function createRotationGuard(options: { + logPath: string; + maxBytes: number; + rotatedLogDir: string; + compress?: boolean; + getLogIdentity: () => FileIdentity | null; + closeLogFile: () => void; + report: (message: string) => void; + onRotated?: (archivePath: string) => void; +}) { const { logPath, maxBytes, rotatedLogDir, compress, getLogIdentity, closeLogFile, report, onRotated } = options; const checkQuantum = Math.max(1, Math.floor(maxBytes / CHECK_QUANTUM_DIVISOR)); const logDir = dirname(logPath); @@ -333,9 +348,9 @@ export function createRotationGuard(options: any) { } function checkAndRotate() { - let active; + let active: BigIntStats; try { - active = statSync(logPath); + active = statSync(logPath, { bigint: true }); } catch (error) { if (error.code !== 'ENOENT') throw error; // The generation this descriptor belongs to has already been rotated away by someone else. @@ -356,12 +371,12 @@ export function createRotationGuard(options: any) { ).catch((error) => report(`Harper could not publish a rotated log file: ${error}`)); } - function holdsGeneration(active: any) { + function holdsGeneration(active: FileIdentity) { const identity = getLogIdentity(); if (!identity) return true; // Some Windows filesystems report an unstable or zero ino, where identity cannot distinguish // generations; there this defers to the size check rather than closing a descriptor at random. - if (identity.ino === 0 || active.ino === 0) return true; + if (!identity.ino || !active.ino) return true; return identity.ino === active.ino && identity.dev === active.dev; } } diff --git a/utility/logging/logRotator.ts b/utility/logging/logRotator.ts index 4328a10f02..f499a2273c 100644 --- a/utility/logging/logRotator.ts +++ b/utility/logging/logRotator.ts @@ -1,6 +1,6 @@ 'use strict'; -import { existsSync, mkdirSync, statSync, promises as fsProm } from 'fs'; +import { type BigIntStats, existsSync, mkdirSync, statSync, promises as fsProm } from 'fs'; import * as path from 'path'; import * as envMgr from '../environment/environmentManager.ts'; envMgr.initSync(); @@ -80,9 +80,9 @@ function logRotator({ let lastRotationTime = Date.now(); let observedGeneration; try { - const active = statSync(logger.path); + const active = statSync(logger.path, { bigint: true }); observedGeneration = generationIdentity(active); - if (active.birthtimeMs > 0) lastRotationTime = Math.min(lastRotationTime, active.birthtimeMs); + if (active.birthtimeMs > 0) lastRotationTime = Math.min(lastRotationTime, Number(active.birthtimeMs)); } catch {} hdbLogger.trace('Log rotate enabled, maxSize:', maxSize, 'interval:', interval); let tickInFlight = false; @@ -124,7 +124,7 @@ function logRotator({ // statSync, and the rename in the same turn: an await here lets a writing thread rotate // the generation this tick measured and start a fresh one, which the tick would then // archive near-empty. - const active = statSync(logger.path); + const active = statSync(logger.path, { bigint: true }); if (active.size >= maxBytes) { lastRotatedLogPath = await moveLogFile(logger.path, rotatedLogDir, logger, compressArchives, active); // The interval clock counts from the last rotation of any kind. Without this an @@ -142,7 +142,7 @@ function logRotator({ if (maxInterval) { try { - const activeGeneration = generationIdentity(statSync(logger.path)); + const activeGeneration = generationIdentity(statSync(logger.path, { bigint: true })); if (activeGeneration && activeGeneration !== observedGeneration) { observedGeneration = activeGeneration; lastRotationTime = Date.now(); @@ -259,7 +259,7 @@ function logRotator({ }, }; - function generationIdentity(stats: any) { + function generationIdentity(stats: BigIntStats) { return stats.ino ? `${stats.dev}:${stats.ino}` : undefined; } } @@ -269,7 +269,7 @@ async function moveLogFile( rotatedLogPath: string, logger?: any, compress?: boolean, - activeStats?: any + activeStats?: BigIntStats ) { // The rename and the descriptor close must not be separated by an await: the descriptor would // otherwise keep feeding the archived inode while the event loop runs. Closing the rotating