diff --git a/src/utils/logging/consolePatch.js b/src/utils/logging/consolePatch.js index eb118ec..d77c886 100644 --- a/src/utils/logging/consolePatch.js +++ b/src/utils/logging/consolePatch.js @@ -1,4 +1,6 @@ // src/utils/logging/consolePatch.js +const util = require("util"); + const { LOG_LEVEL, LOG_LEVELS } = require("./config"); function shouldLog(level) { @@ -7,6 +9,57 @@ const originalConsole = { ...console }; +function patchConsole(logStreams, sessionTransport) { + console.log = (...args) => + writeLog( + "INFO", + logStreams.info, + originalConsole.log, + sessionTransport, + ...args + ); + console.error = (...args) => + writeLog( + "ERROR", + logStreams.error, + originalConsole.error, + sessionTransport, + ...args + ); + console.warn = (...args) => + writeLog( + "WARN", + logStreams.warn, + originalConsole.warn, + sessionTransport, + ...args + ); + console.info = (...args) => + writeLog( + "INFO", + logStreams.info, + originalConsole.info, + sessionTransport, + ...args + ); + console.debug = (...args) => + writeLog( + "DEBUG", + logStreams.debug, + originalConsole.debug, + sessionTransport, + ...args + ); + return originalConsole; +} + +function unpatchConsole() { + console.log = originalConsole.log; + console.error = originalConsole.error; + console.warn = originalConsole.warn; + console.info = originalConsole.info; + console.debug = originalConsole.debug; +} function getCircularReplacer() { const seen = new WeakSet(); return (key, value) => { @@ -19,38 +72,47 @@ return value; }; } +function formatArg(arg) { + if (arg instanceof Error) { + return JSON.stringify( + { + name: arg.name, + message: arg.message, + stack: arg.stack, + }, + null, + 2 + ); + } -function patchConsole(logStreams) { - console.log = (...args) => - writeLog("INFO", logStreams.info, originalConsole.log, ...args); - console.error = (...args) => - writeLog("ERROR", logStreams.error, originalConsole.error, ...args); - console.warn = (...args) => - writeLog("WARN", logStreams.warn, originalConsole.warn, ...args); - console.info = (...args) => - writeLog("INFO", logStreams.info, originalConsole.info, ...args); - console.debug = (...args) => - writeLog("DEBUG", logStreams.debug, originalConsole.debug, ...args); + if (arg instanceof RegExp) { + return arg.toString(); + } + + if (typeof arg === "object" && arg !== null) { + try { + return JSON.stringify(arg, getCircularReplacer(), 2); + } catch { + return util.inspect(arg, { depth: null, colors: false }); + } + } + + return String(arg); +} + +function formatLog(level, ...args) { + const timestamp = new Date().toISOString(); + const safeArgs = args.map(formatArg); + const message = safeArgs.join(" "); + const logLine = `[${timestamp}] [${level}] ${message}\n`; + + return { timestamp, safeArgs, message, logLine }; } function writeLog(level, stream, consoleFn, sessionTransport, ...args) { if (!shouldLog(level)) return; - const timestamp = new Date().toISOString(); - - const safeArgs = args.map((arg) => { - if (typeof arg === "object") { - try { - return JSON.stringify(arg, getCircularReplacer(), 2); - } catch { - return require("util").inspect(arg, { depth: null, colors: false }); - } - } - return String(arg); - }); - - const message = safeArgs.join(" "); - const logLine = `[${timestamp}] [${level}] ${message}\n`; + const { timestamp, safeArgs, message, logLine } = formatLog(level, ...args); stream.write(logLine); sessionTransport.write({ level: level.toLowerCase(), message, timestamp }); @@ -59,6 +121,8 @@ module.exports = { patchConsole, + unpatchConsole, shouldLog, writeLog, + formatLog, }; diff --git a/src/utils/logging/index.js b/src/utils/logging/index.js index 18bd09d..71a76a4 100644 --- a/src/utils/logging/index.js +++ b/src/utils/logging/index.js @@ -45,6 +45,7 @@ const logStreams = createLogStreams(logFiles); const sessionTransport = createSessionTransport(sessionDir); const sqliteTransport = new SQLiteTransport(); +patchConsole(logStreams, sessionTransport); const manualLogger = { streams: logStreams, diff --git a/test/units/utils/logging/formatLog.test.js b/test/units/utils/logging/formatLog.test.js new file mode 100644 index 0000000..c073a81 --- /dev/null +++ b/test/units/utils/logging/formatLog.test.js @@ -0,0 +1,26 @@ +const { formatLog } = require("../../../../src/utils/logging/consolePatch"); +const { expect } = require("chai"); + +describe("Logger Format Function Tests", () => { + it("should format circular objects without throwing and stringify correctly", () => { + const circular = { name: "test" }; + circular.ref = circular; + + const methods = ["INFO", "WARN", "ERROR", "DEBUG", "NOTICE"]; + + methods.forEach((level) => { + const { timestamp, safeArgs, message, logLine } = formatLog( + level, + circular + ); + + expect(timestamp).to.match(/\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}.\d{3}Z/); + expect(safeArgs).to.be.an("array"); + expect(message).to.include("name"); + expect(message).to.include("test"); + expect(message).to.not.include("[object Object]"); + expect(logLine).to.include(`[${timestamp}] [${level}]`); + expect(logLine).to.include(message); + }); + }); +}); diff --git a/test/units/utils/logging/object-formatting.test.js b/test/units/utils/logging/object-formatting.test.js index f15e4c9..0649a60 100644 --- a/test/units/utils/logging/object-formatting.test.js +++ b/test/units/utils/logging/object-formatting.test.js @@ -317,42 +317,6 @@ consoleErrorStub.restore(); }); - - xit("should handle circular objects in all manual logger methods", () => { - const circular = { name: "test" }; - circular.ref = circular; - - const methods = ["info", "warn", "error", "debug", "notice"]; - const consoleMethodMap = { - info: "log", - notice: "log", - warn: "warn", - error: "error", - debug: "debug", - }; - - methods.forEach((method) => { - const sandbox = sinon.createSandbox(); - const consoleMethod = consoleMethodMap[method]; - - const methodStub = sandbox - .stub(console, consoleMethod) - .callsFake(() => {}); - - manualLogger[method](circular); - - expect(methodStub.called).to.be.true; // the offending line - - const consoleArgs = methodStub.getCall(0).args; - const output = consoleArgs.map(String).join(" "); - - expect(output).to.include("name"); - expect(output).to.include("test"); - expect(output).to.not.include("[object Object]"); - - sandbox.restore(); - }); - }); }); describe("Winston Logger", () => { @@ -555,49 +519,3 @@ }); }); }); - -const consolePatch = require("../../../../src/utils/logging/consolePatch"); - -describe("Logger Object Expansion Tests", () => { - let shouldLogStub; - - before(() => { - shouldLogStub = sinon.stub(consolePatch, "shouldLog").returns(true); - }); - - after(() => { - shouldLogStub.restore(); - }); - - it("should handle circular objects in all manual logger methods", () => { - const circular = { name: "test" }; - circular.ref = circular; - - const methods = ["info", "warn", "error", "debug", "notice"]; - const consoleMethodMap = { - info: "log", - notice: "log", - warn: "warn", - error: "error", - debug: "debug", - }; - - methods.forEach((method) => { - const sandbox = sinon.createSandbox(); - const consoleMethod = consoleMethodMap[method]; - - const methodStub = sandbox.stub(console, consoleMethod); - - manualLogger[method](circular); - - expect(methodStub.called).to.be.true; - - const output = methodStub.getCall(0).args.map(String).join(" "); - expect(output).to.include("name"); - expect(output).to.include("test"); - expect(output).to.not.include("[object Object]"); - - sandbox.restore(); - }); - }); -}); diff --git a/test/units/utils/logging/object_expansion/edge_cases.js b/test/units/utils/logging/object_expansion/edge_cases.js deleted file mode 100644 index d971dea..0000000 --- a/test/units/utils/logging/object_expansion/edge_cases.js +++ /dev/null @@ -1,144 +0,0 @@ -const { expect } = require("chai"); -const sinon = require("sinon"); -const { Writable } = require("stream"); - -// Mock dependencies -const mockLogStreams = { - info: new Writable({ write() {} }), - error: new Writable({ write() {} }), - warn: new Writable({ write() {} }), - debug: new Writable({ write() {} }), - notice: new Writable({ write() {} }), -}; - -const mockSessionTransport = { - write: sinon.stub(), -}; - -// Import the modules under test -const { writeLog } = require("../../../../../src/utils/logging/consolePatch"); -describe("Edge Cases", () => { - let consoleLogStub; // Declare stub for this describe block - - beforeEach(() => { - // Stub console.log specifically for this describe block - consoleLogStub = sinon.stub(console, "log"); - }); - - afterEach(() => { - // Restore console.log stub after each test in this block - consoleLogStub.restore(); - }); - - it("should handle null and undefined without [object Object]", () => { - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - null, - undefined - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("null"); - expect(outputString).to.include("undefined"); - }); - - it("should handle objects with null prototype", () => { - const nullProtoObj = Object.create(null); - nullProtoObj.key = "value"; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - nullProtoObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("key"); - expect(outputString).to.include("value"); - }); - - it("should handle Date objects", () => { - const dateObj = new Date("2023-01-01T12:00:00.000Z"); // Use ISO string for consistent output - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - dateObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - // Check for parts of the date string that are likely to be present in ISO format - // Console.log's output for Date objects can vary, but the ISO string is often included or derived. - expect(outputString).to.include("2023"); - // Check for the time part of the ISO string for more robustness - expect(outputString).to.include("T12:00:00.000Z"); - }); - - it("should handle RegExp objects", () => { - const regexObj = /test.*pattern/gi; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - regexObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("test"); - expect(outputString).to.include("pattern"); - expect(outputString).to.include("gi"); // Check for flags - }); - - it("should handle very deeply nested objects", () => { - let deepObj = { level: 0 }; - let current = deepObj; - - // Create 10 levels deep - for (let i = 1; i <= 10; i++) { - current.next = { level: i }; - current = current.next; - } - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - deepObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("level"); - // Check for presence of multiple levels - expect(outputString.match(/level/g).length).to.be.at.least(10); - }); -}); diff --git a/test/units/utils/logging/object_expansion/stream_output_validation.js b/test/units/utils/logging/object_expansion/stream_output_validation.js deleted file mode 100644 index c437ecd..0000000 --- a/test/units/utils/logging/object_expansion/stream_output_validation.js +++ /dev/null @@ -1,62 +0,0 @@ -const { expect } = require("chai"); -const sinon = require("sinon"); -const { Writable } = require("stream"); - -// Mock dependencies -const mockLogStreams = { - info: new Writable({ write() {} }), - error: new Writable({ write() {} }), - warn: new Writable({ write() {} }), - debug: new Writable({ write() {} }), - notice: new Writable({ write() {} }), -}; - -const mockSessionTransport = { - write: sinon.stub(), -}; - -// Import the modules under test -const { writeLog } = require("../../../../../src/utils/logging/consolePatch"); - -describe("Stream Output Validation", () => { - let consoleLogStub; // Declare stub for this describe block - - beforeEach(() => { - // Stub console.log specifically for this describe block - consoleLogStub = sinon.stub(console, "log"); - }); - - afterEach(() => { - // Restore console.log stub after each test in this block - consoleLogStub.restore(); - }); - - it("should ensure stream writes never contain [object Object]", () => { - const testObjects = [ - { simple: "object" }, - { nested: { deep: { value: "test" } } }, - [{ array: "item" }], - { mixed: ["array", { in: "object" }] }, - ]; - - testObjects.forEach((obj, index) => { - streamWriteStubs.info.resetHistory(); // Reset history for each iteration - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - obj - ); - - expect(streamWriteStubs.info.called).to.be.true; - const streamWrites = streamWriteStubs.info.getCalls(); - streamWrites.forEach((call) => { - const writeData = call.args[0]; - // Ensure the written data is a string and does not contain "[object Object]" - expect(typeof writeData).to.equal("string"); - expect(writeData).to.not.include("[object Object]"); - }); - }); - }); -}); diff --git a/test/units/utils/logging/object_expansion/winstonLogger.js b/test/units/utils/logging/object_expansion/winstonLogger.js deleted file mode 100644 index 3bf09aa..0000000 --- a/test/units/utils/logging/object_expansion/winstonLogger.js +++ /dev/null @@ -1,35 +0,0 @@ -const { expect } = require("chai"); -const sinon = require("sinon"); - -const { winstonLogger } = require("../../../../../src/utils/logging/index"); - -describe("Winston Logger", () => { - let winstonInfoStub; - - beforeEach(() => { - winstonInfoStub = sinon.stub(winstonLogger, "info"); - }); - - afterEach(() => { - winstonInfoStub.restore(); // Ensure winston stub is restored - }); - - it("should not produce [object Object] in winston logs", () => { - const logData = { - user: { id: 456, name: "Jane" }, - action: "update", - metadata: { timestamp: Date.now() }, - }; - - winstonLogger.info("User action", logData); - - // Check that winston was called with properly formatted data - expect(winstonInfoStub.called).to.be.true; - const logCall = winstonInfoStub.getCall(0).args; - // Winston typically stringifies objects, so we check the stringified output - const logString = JSON.stringify(logCall); - expect(logString).to.not.include("[object Object]"); - expect(logString).to.include("Jane"); - expect(logString).to.include("update"); - }); -}); diff --git a/test/units/utils/logging/object_expansion/writeLog.js b/test/units/utils/logging/object_expansion/writeLog.js deleted file mode 100644 index f1f8407..0000000 --- a/test/units/utils/logging/object_expansion/writeLog.js +++ /dev/null @@ -1,220 +0,0 @@ -const { expect } = require("chai"); -const sinon = require("sinon"); -const { Writable } = require("stream"); - -// Mock dependencies -const mockLogStreams = { - info: new Writable({ write() {} }), - error: new Writable({ write() {} }), - warn: new Writable({ write() {} }), - debug: new Writable({ write() {} }), - notice: new Writable({ write() {} }), -}; - -const mockSessionTransport = { - write: sinon.stub(), -}; - -// Import the modules under test -const { writeLog } = require("../../../../../src/utils/logging/consolePatch"); -describe("writeLog function", () => { - let consoleLogStub; // Declare stub for this describe block - - beforeEach(() => { - // Stub console.log specifically for this describe block - consoleLogStub = sinon.stub(console, "log"); - }); - - afterEach(() => { - // Restore console.log stub after each test in this block - consoleLogStub.restore(); - }); - - it("should never log [object Object] for simple objects", () => { - const testObject = { name: "test", value: 42 }; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - testObject - ); - - // Check console output - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("name"); - expect(outputString).to.include("test"); - expect(outputString).to.include("value"); - expect(outputString).to.include("42"); - - // Check stream output - expect(streamWriteStubs.info.called).to.be.true; - const streamOutput = streamWriteStubs.info.getCall(0).args[0]; - expect(streamOutput).to.not.include("[object Object]"); - expect(streamOutput).to.include("name"); - expect(streamOutput).to.include("test"); - }); - - it("should properly expand nested objects", () => { - const nestedObject = { - user: { - id: 123, - profile: { - name: "John Doe", - settings: { theme: "dark", notifications: true }, - }, - }, - }; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - nestedObject - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("John Doe"); - expect(outputString).to.include("theme"); - expect(outputString).to.include("dark"); - expect(outputString).to.include("notifications"); - }); - - it("should handle circular references without [object Object]", () => { - const circularObj = { name: "circular" }; - circularObj.self = circularObj; - circularObj.nested = { parent: circularObj }; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - circularObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("name"); - expect(outputString).to.include("circular"); - // Should handle circular reference gracefully - expect(outputString).to.include("self"); - }); - - it("should expand arrays containing objects", () => { - const arrayWithObjects = [ - { id: 1, name: "first" }, - { id: 2, name: "second", nested: { value: "test" } }, - ]; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - arrayWithObjects - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("first"); - expect(outputString).to.include("second"); - expect(outputString).to.include("nested"); - expect(outputString).to.include("test"); - }); - - it("should handle mixed argument types without [object Object]", () => { - const mixedArgs = [ - "String message", - { obj: "value" }, - 42, - ["array", "items"], - { deeply: { nested: { object: "here" } } }, - ]; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - ...mixedArgs - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("String message"); - expect(outputString).to.include("obj"); - expect(outputString).to.include("value"); - expect(outputString).to.include("deeply"); - expect(outputString).to.include("here"); - }); - - it("should handle Error objects without [object Object]", () => { - const error = new Error("Test error"); - error.customProperty = { details: "additional info" }; - - // Stub console.error for this test (local stub, not interfering with console.log stub) - const consoleErrorStub = sinon.stub(console, "error"); - - writeLog( - "ERROR", - mockLogStreams.error, - console.error, - mockSessionTransport, - error - ); - - expect(consoleErrorStub.called).to.be.true; - const consoleArgs = consoleErrorStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("Test error"); - - consoleErrorStub.restore(); - }); - - it("should handle objects with special properties", () => { - const specialObj = { - toString: () => "custom toString", - valueOf: () => 99, - [Symbol.toStringTag]: "CustomObject", - normalProp: "normal value", - }; - - writeLog( - "INFO", - mockLogStreams.info, - console.log, - mockSessionTransport, - specialObj - ); - - expect(consoleLogStub.called).to.be.true; - const consoleArgs = consoleLogStub.getCall(0).args; - expect(consoleArgs).to.exist; - const outputString = consoleArgs.join(" "); - expect(outputString).to.not.include("[object Object]"); - expect(outputString).to.include("normalProp"); - expect(outputString).to.include("normal value"); - }); -});