refactor: decouple logging from winston

packages/config/src/ConfigManager.test.ts

@@ -1,5 +1,6 @@
-import { ZWaveLogContainer } from "@zwave-js/core";
+import { type LogContainer } from "@zwave-js/core";
 import { fs } from "@zwave-js/core/bindings/fs/node";
+import { log as createZWaveLogContainer } from "@zwave-js/core/bindings/log/node";
 import { pathExists } from "@zwave-js/shared";
 import fsp from "node:fs/promises";
 import { tmpdir } from "node:os";
@@ -13,7 +14,7 @@ import { syncExternalConfigDir } from "./utils.js";
 interface LocalTestContext {
 	context: {
 		tempDir: string;
-		logContainer: ZWaveLogContainer;
+		logContainer: LogContainer;
 		logger: ConfigLogger;
 	};
 }
@@ -28,7 +29,7 @@ const test = baseTest.extend<LocalTestContext>({
 			const tempDir = path.join(tmpdir(), "zwavejs_test");
 			await fsp.mkdir(tempDir, { recursive: true });
 
-			const logContainer = new ZWaveLogContainer({ enabled: false });
+			const logContainer = createZWaveLogContainer({ enabled: false });
 			const logger = new ConfigLogger(logContainer);
 
 			// Run tests
@@ -213,7 +214,7 @@ async function testDeviceConfigPriorityDir(
 	// And load the file
 	const cm = new ConfigManager({
 		deviceConfigPriorityDir: priorityDir,
-		logContainer: new ZWaveLogContainer({ enabled: false }),
+		logContainer: createZWaveLogContainer({ enabled: false }),
 	});
 	await cm.loadAll();
 

packages/config/src/ConfigManager.ts

@@ -1,9 +1,10 @@
 import {
+	type LogContainer,
 	ZWaveError,
 	ZWaveErrorCodes,
-	ZWaveLogContainer,
 	isZWaveError,
 } from "@zwave-js/core";
+import { log as createZWaveLogContainer } from "@zwave-js/core/bindings/log/node";
 import { getErrorMessage, pathExists } from "@zwave-js/shared";
 import { type FileSystem } from "@zwave-js/shared/bindings";
 import path from "pathe";
@@ -34,7 +35,7 @@ import {
 
 export interface ConfigManagerOptions {
 	bindings?: FileSystem;
-	logContainer?: ZWaveLogContainer;
+	logContainer?: LogContainer;
 	deviceConfigPriorityDir?: string;
 	deviceConfigExternalDir?: string;
 }
@@ -43,7 +44,7 @@ export class ConfigManager {
 	public constructor(options: ConfigManagerOptions = {}) {
 		this._fs = options.bindings;
 		this.logger = new ConfigLogger(
-			options.logContainer ?? new ZWaveLogContainer({ enabled: false }),
+			options.logContainer ?? createZWaveLogContainer({ enabled: false }),
 		);
 		this.deviceConfigPriorityDir = options.deviceConfigPriorityDir;
 		this.deviceConfigExternalDir = options.deviceConfigExternalDir;

packages/config/src/Logger.ts

@@ -1,5 +1,5 @@
 import {
-	type ZWaveLogContainer,
+	type LogContainer,
 	ZWaveLoggerBase,
 	getDirectionPrefix,
 } from "@zwave-js/core";
@@ -10,7 +10,7 @@ import {
 } from "./Logger_safe.js";
 
 export class ConfigLogger extends ZWaveLoggerBase<ConfigLogContext> {
-	constructor(loggers: ZWaveLogContainer) {
+	constructor(loggers: LogContainer) {
 		super(loggers, CONFIG_LABEL);
 	}
 

packages/core/src/bindings/log/node.ts

@@ -0,0 +1,281 @@
+import path from "pathe";
+import { configs } from "triple-beam";
+import winston from "winston";
+import DailyRotateFile from "winston-daily-rotate-file";
+import type Transport from "winston-transport";
+import type { ConsoleTransportInstance } from "winston/lib/winston/transports";
+import {
+	createDefaultTransportFormat,
+	createLoggerFormat,
+} from "../../log/shared.js";
+import {
+	type LogConfig,
+	type LogContext,
+	type LogFactory,
+	nonUndefinedLogConfigKeys,
+	stringToNodeList,
+} from "../../log/shared_safe.js";
+import { type LogContainer, type ZWaveLogger } from "../../log/traits.js";
+
+const isTTY = process.stdout.isTTY;
+const isUnitTest = process.env.NODE_ENV === "test";
+
+const loglevels = configs.npm.levels;
+
+function getTransportLoglevel(): string {
+	return process.env.LOGLEVEL! in loglevels ? process.env.LOGLEVEL! : "debug";
+}
+
+/** Performs a reverse lookup of the numeric loglevel */
+function loglevelFromNumber(numLevel: number | undefined): string | undefined {
+	if (numLevel == undefined) return;
+	for (const [level, value] of Object.entries(loglevels)) {
+		if (value === numLevel) return level;
+	}
+}
+
+class ZWaveLogContainer<TContext extends LogContext> extends winston.Container
+	implements LogContainer
+{
+	private fileTransport: DailyRotateFile | undefined;
+	private consoleTransport: ConsoleTransportInstance | undefined;
+	private loglevelVisibleCache = new Map<string, boolean>();
+
+	private logConfig: LogConfig & { level: string } = {
+		enabled: true,
+		level: getTransportLoglevel(),
+		logToFile: !!process.env.LOGTOFILE,
+		maxFiles: 7,
+		nodeFilter: stringToNodeList(process.env.LOG_NODES),
+		transports: undefined as any,
+		filename: path.join(process.cwd(), `zwavejs_%DATE%.log`),
+		forceConsole: false,
+	};
+
+	constructor(config: Partial<LogConfig> = {}) {
+		super();
+		this.updateConfiguration(config);
+	}
+
+	public getLogger(label: string): ZWaveLogger<TContext> {
+		if (!this.has(label)) {
+			this.add(label, {
+				transports: this.getAllTransports(),
+				format: createLoggerFormat(label),
+				// Accept all logs, no matter what. The individual loggers take care
+				// of filtering the wrong loglevels
+				level: "silly",
+			});
+		}
+
+		return this.get(label) as unknown as ZWaveLogger<TContext>;
+	}
+
+	public updateConfiguration(config: Partial<LogConfig>): void {
+		// Avoid overwriting configuration settings with undefined if they shouldn't be
+		for (const key of nonUndefinedLogConfigKeys) {
+			if (key in config && config[key] === undefined) {
+				delete config[key];
+			}
+		}
+		const changedLoggingTarget = (config.logToFile != undefined
+			&& config.logToFile !== this.logConfig.logToFile)
+			|| (config.forceConsole != undefined
+				&& config.forceConsole !== this.logConfig.forceConsole);
+
+		if (typeof config.level === "number") {
+			config.level = loglevelFromNumber(config.level);
+		}
+		const changedLogLevel = config.level != undefined
+			&& config.level !== this.logConfig.level;
+
+		if (
+			config.filename != undefined
+			&& !config.filename.includes("%DATE%")
+		) {
+			config.filename += "_%DATE%.log";
+		}
+		const changedFilename = config.filename != undefined
+			&& config.filename !== this.logConfig.filename;
+
+		if (config.maxFiles != undefined) {
+			if (
+				typeof config.maxFiles !== "number"
+				|| config.maxFiles < 1
+				|| config.maxFiles > 365
+			) {
+				delete config.maxFiles;
+			}
+		}
+		const changedMaxFiles = config.maxFiles != undefined
+			&& config.maxFiles !== this.logConfig.maxFiles;
+
+		this.logConfig = Object.assign(this.logConfig, config);
+
+		// If the loglevel changed, our cached "is visible" info is out of date
+		if (changedLogLevel) {
+			this.loglevelVisibleCache.clear();
+		}
+
+		// When the log target (console, file, filename) was changed, recreate the internal transports
+		// because at least the filename does not update dynamically
+		// Also do this when configuring the logger for the first time
+		const recreateInternalTransports = (this.fileTransport == undefined
+			&& this.consoleTransport == undefined)
+			|| changedLoggingTarget
+			|| changedFilename
+			|| changedMaxFiles;
+
+		if (recreateInternalTransports) {
+			this.fileTransport?.destroy();
+			this.fileTransport = undefined;
+			this.consoleTransport?.destroy();
+			this.consoleTransport = undefined;
+		}
+
+		// When the internal transports or the custom transports were changed, we need to update the loggers
+		if (recreateInternalTransports || config.transports != undefined) {
+			this.loggers.forEach((logger) =>
+				logger.configure({ transports: this.getAllTransports() })
+			);
+		}
+	}
+
+	public getConfiguration(): LogConfig {
+		return this.logConfig;
+	}
+
+	/** Tests whether a log using the given loglevel will be logged */
+	public isLoglevelVisible(loglevel: string): boolean {
+		// If we are not connected to a TTY, not logging to a file and don't have any custom transports, we won't see anything
+		if (
+			!this.fileTransport
+			&& !this.consoleTransport
+			&& (!this.logConfig.transports
+				|| this.logConfig.transports.length === 0)
+		) {
+			return false;
+		}
+
+		if (!this.loglevelVisibleCache.has(loglevel)) {
+			this.loglevelVisibleCache.set(
+				loglevel,
+				loglevel in loglevels
+					&& loglevels[loglevel] <= loglevels[this.logConfig.level],
+			);
+		}
+		return this.loglevelVisibleCache.get(loglevel)!;
+	}
+
+	public destroy(): void {
+		for (const key in this.loggers) {
+			this.close(key);
+		}
+
+		this.fileTransport = undefined;
+		this.consoleTransport = undefined;
+		this.logConfig.transports = [];
+	}
+
+	private getAllTransports(): Transport[] {
+		return [
+			...this.getInternalTransports(),
+			...(this.logConfig.transports ?? []),
+		];
+	}
+
+	private getInternalTransports(): Transport[] {
+		const ret: Transport[] = [];
+
+		// If logging is disabled, don't log to any of the default transports
+		if (!this.logConfig.enabled) {
+			return ret;
+		}
+
+		// Log to file only when opted in
+		if (this.logConfig.logToFile) {
+			if (!this.fileTransport) {
+				this.fileTransport = this.createFileTransport();
+			}
+			ret.push(this.fileTransport);
+		}
+
+		// Console logs can be noise, so only log to console...
+		if (
+			// when in production
+			!isUnitTest
+			// and stdout is a TTY while we're not already logging to a file
+			&& ((isTTY && !this.logConfig.logToFile)
+				// except when the user explicitly wants to
+				|| this.logConfig.forceConsole)
+		) {
+			if (!this.consoleTransport) {
+				this.consoleTransport = this.createConsoleTransport();
+			}
+			ret.push(this.consoleTransport);
+		}
+
+		return ret;
+	}
+
+	private createConsoleTransport(): ConsoleTransportInstance {
+		return new winston.transports.Console({
+			format: createDefaultTransportFormat(
+				// Only colorize the output if logging to a TTY, otherwise we'll get
+				// ansi color codes in logfiles or redirected shells
+				isTTY || isUnitTest,
+				// Only use short timestamps if logging to a TTY
+				isTTY,
+			),
+			silent: this.isConsoleTransportSilent(),
+		});
+	}
+
+	private isConsoleTransportSilent(): boolean {
+		return process.env.NODE_ENV === "test" || !this.logConfig.enabled;
+	}
+
+	private isFileTransportSilent(): boolean {
+		return !this.logConfig.enabled;
+	}
+
+	private createFileTransport(): DailyRotateFile {
+		const ret = new DailyRotateFile({
+			filename: this.logConfig.filename,
+			auditFile: `${
+				this.logConfig.filename
+					.replace("_%DATE%", "_logrotate")
+					.replace(/\.log$/, "")
+			}.json`,
+			datePattern: "YYYY-MM-DD",
+			createSymlink: true,
+			symlinkName: path
+				.basename(this.logConfig.filename)
+				.replace(`_%DATE%`, "_current"),
+			zippedArchive: true,
+			maxFiles: `${this.logConfig.maxFiles}d`,
+			format: createDefaultTransportFormat(false, false),
+			silent: this.isFileTransportSilent(),
+		});
+		ret.on("new", (newFilename: string) => {
+			console.log(`Logging to file:
+	${newFilename}`);
+		});
+		ret.on("error", (err: Error) => {
+			console.error(`Error in file stream rotator: ${err.message}`);
+		});
+		return ret;
+	}
+
+	/**
+	 * Checks the log configuration whether logs should be written for a given node id
+	 */
+	public isNodeLoggingVisible(nodeId: number): boolean {
+		// If no filters are set, every node gets logged
+		if (!this.logConfig.nodeFilter) return true;
+		return this.logConfig.nodeFilter.includes(nodeId);
+	}
+}
+
+export const log: LogFactory = (config?: Partial<LogConfig>) =>
+	new ZWaveLogContainer(config);

packages/core/src/index.ts

@@ -1,13 +1,14 @@
-/* eslint-disable @typescript-eslint/consistent-type-exports */
 export * from "./crypto/index.js";
 export * from "./definitions/index.js";
 export * from "./dsk/index.js";
 export * from "./error/ZWaveError.js";
 export * from "./fsm/FSM.js";
 export * from "./log/Controller.definitions.js";
 export * from "./log/Controller.js";
+export * from "./log/ZWaveLoggerBase.js";
 export * from "./log/shared.js";
 export * from "./log/shared_safe.js";
+export type * from "./log/traits.js";
 export * from "./qr/index.js";
 export * from "./reflection/decorators.js";
 export * from "./registries/index.js";
@@ -17,7 +18,7 @@ export * from "./security/Manager2Types.js";
 export * from "./security/ctr_drbg.js";
 export * from "./test/assertZWaveError.js";
 export type * from "./traits/index.js";
-export * from "./util/_Types.js";
+export type * from "./util/_Types.js";
 export * from "./util/compareVersions.js";
 export { deflateSync, gunzipSync } from "./util/compression.js";
 export * from "./util/config.js";
@@ -33,4 +34,4 @@ export * from "./values/Metadata.js";
 export * from "./values/Primitive.js";
 export * from "./values/Timeout.js";
 export * from "./values/ValueDB.js";
-export * from "./values/_Types.js";
+export type * from "./values/_Types.js";