diff --git a/packages/node_modules/@node-red/util/lib/log.js b/packages/node_modules/@node-red/util/lib/log.js index 341019080..7b7e9b2dc 100644 --- a/packages/node_modules/@node-red/util/lib/log.js +++ b/packages/node_modules/@node-red/util/lib/log.js @@ -75,12 +75,28 @@ LogHandler.prototype.shouldReportMessage = function(msglevel) { msglevel <= this.logLevel; } + +// Older versions of Node-RED used the deprecated util.log function. +// With Node.js 22, use of that function causes warnings. So here we +// are replicating the same format output to ensure we don't break any +// log parsing that happens in the real world. +const months = ['Jan', 'Feb', 'Mar', 'Apr', 'May', 'Jun', 'Jul', 'Aug', 'Sep', 'Oct', 'Nov', 'Dec']; +const utilLog = function (msg) { + const d = new Date(); + const time = [ + d.getHours().toString().padStart(2, '0'), + d.getMinutes().toString().padStart(2, '0'), + d.getSeconds().toString().padStart(2, '0') + ].join(':'); + console.log(`${d.getDate()} ${months[d.getMonth()]} ${time} - ${msg}`) +} + var consoleLogger = function(msg) { if (msg.level == log.METRIC || msg.level == log.AUDIT) { - util.log("["+levelNames[msg.level]+"] "+JSON.stringify(msg)); + utilLog("["+levelNames[msg.level]+"] "+JSON.stringify(msg)); } else { if (verbose && msg.msg && msg.msg.stack) { - util.log("["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+msg.msg.stack); + utilLog("["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+msg.msg.stack); } else { var message = msg.msg; try { @@ -91,7 +107,7 @@ var consoleLogger = function(msg) { message = 'Exception trying to log: '+util.inspect(message); } - util.log("["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+message); + utilLog("["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+message); } } } diff --git a/test/unit/@node-red/util/lib/log_spec.js b/test/unit/@node-red/util/lib/log_spec.js index 056f37672..8fe09b3bf 100644 --- a/test/unit/@node-red/util/lib/log_spec.js +++ b/test/unit/@node-red/util/lib/log_spec.js @@ -24,38 +24,38 @@ var log = NR_TEST_UTILS.require("@node-red/util").log; describe("@node-red/util/log", function() { beforeEach(function () { - var spy = sinon.stub(util, 'log').callsFake(function(arg){}); + var spy = sinon.stub(console, 'log').callsFake(function(arg){}); var settings = {logging: { console: { level: 'metric', metrics: true } } }; log.init(settings); }); afterEach(function() { - util.log.restore(); + console.log.restore(); }); it('it can raise an error', function() { var ret = log.error("This is an error"); - sinon.assert.calledWithMatch(util.log,"[error] This is an error"); + sinon.assert.calledWithMatch(console.log,"[error] This is an error"); }); it('it can raise a trace', function() { var ret = log.trace("This is a trace"); - sinon.assert.calledWithMatch(util.log,"[trace] This is a trace"); + sinon.assert.calledWithMatch(console.log,"[trace] This is a trace"); }); it('it can raise a debug', function() { var ret = log.debug("This is a debug"); - sinon.assert.calledWithMatch(util.log,"[debug] This is a debug"); + sinon.assert.calledWithMatch(console.log,"[debug] This is a debug"); }); it('it can raise a info', function() { var ret = log.info("This is an info"); - sinon.assert.calledWithMatch(util.log,"[info] This is an info"); + sinon.assert.calledWithMatch(console.log,"[info] This is an info"); }); it('it can raise a warn', function() { var ret = log.warn("This is a warn"); - sinon.assert.calledWithMatch(util.log,"[warn] This is a warn"); + sinon.assert.calledWithMatch(console.log,"[warn] This is a warn"); }); it('it can raise a metric', function() { @@ -66,9 +66,10 @@ describe("@node-red/util/log", function() { metrics.msgid = "12345"; metrics.value = "the metric payload"; var ret = log.log(metrics); - util.log.calledOnce.should.be.true(); - util.log.firstCall.args[0].indexOf("[metric] ").should.equal(0); - var body = JSON.parse(util.log.firstCall.args[0].substring(9)); + console.log.calledOnce.should.be.true(); + console.log.firstCall.args[0].indexOf("[metric]").should.not.equal(-1); + const parts = console.log.firstCall.args[0].split("[metric] ") + var body = JSON.parse(parts[1]) body.should.have.a.property("nodeid","testid"); body.should.have.a.property("event","node.test.testevent"); body.should.have.a.property("msgid","12345"); @@ -86,13 +87,13 @@ describe("@node-red/util/log", function() { it('it logs node type and name if provided',function() { log.log({level:log.INFO,type:"nodeType",msg:"test",name:"nodeName",id:"nodeId"}); - util.log.calledOnce.should.be.true(); - util.log.firstCall.args[0].indexOf("[nodeType:nodeName]").should.not.equal(-1); + console.log.calledOnce.should.be.true(); + console.log.firstCall.args[0].indexOf("[nodeType:nodeName]").should.not.equal(-1); }); it('it logs node type and id if no name provided',function() { log.log({level:log.INFO,type:"nodeType",msg:"test",id:"nodeId"}); - util.log.calledOnce.should.be.true(); - util.log.firstCall.args[0].indexOf("[nodeType:nodeId]").should.not.equal(-1); + console.log.calledOnce.should.be.true(); + console.log.firstCall.args[0].indexOf("[nodeType:nodeId]").should.not.equal(-1); }); it('ignores lower level messages and metrics', function() { @@ -104,12 +105,12 @@ describe("@node-red/util/log", function() { log.debug("This is a debug"); log.trace("This is a trace"); log.log({level:log.METRIC,msg:"testMetric"}); - sinon.assert.calledWithMatch(util.log,"[error] This is an error"); - sinon.assert.calledWithMatch(util.log,"[warn] This is a warn"); - sinon.assert.neverCalledWithMatch(util.log,"[info] This is an info"); - sinon.assert.neverCalledWithMatch(util.log,"[debug] This is a debug"); - sinon.assert.neverCalledWithMatch(util.log,"[trace] This is a trace"); - sinon.assert.neverCalledWithMatch(util.log,"[metric] "); + sinon.assert.calledWithMatch(console.log,"[error] This is an error"); + sinon.assert.calledWithMatch(console.log,"[warn] This is a warn"); + sinon.assert.neverCalledWithMatch(console.log,"[info] This is an info"); + sinon.assert.neverCalledWithMatch(console.log,"[debug] This is a debug"); + sinon.assert.neverCalledWithMatch(console.log,"[trace] This is a trace"); + sinon.assert.neverCalledWithMatch(console.log,"[metric] "); }); it('ignores lower level messages but accepts metrics', function() { var settings = {logging: { console: { level: 'log', metrics: true } } }; @@ -120,12 +121,12 @@ describe("@node-red/util/log", function() { log.debug("This is a debug"); log.trace("This is a trace"); log.log({level:log.METRIC,msg:"testMetric"}); - sinon.assert.calledWithMatch(util.log,"[error] This is an error"); - sinon.assert.calledWithMatch(util.log,"[warn] This is a warn"); - sinon.assert.calledWithMatch(util.log,"[info] This is an info"); - sinon.assert.neverCalledWithMatch(util.log,"[debug] This is a debug"); - sinon.assert.neverCalledWithMatch(util.log,"[trace] This is a trace"); - sinon.assert.calledWithMatch(util.log,"[metric] "); + sinon.assert.calledWithMatch(console.log,"[error] This is an error"); + sinon.assert.calledWithMatch(console.log,"[warn] This is a warn"); + sinon.assert.calledWithMatch(console.log,"[info] This is an info"); + sinon.assert.neverCalledWithMatch(console.log,"[debug] This is a debug"); + sinon.assert.neverCalledWithMatch(console.log,"[trace] This is a trace"); + sinon.assert.calledWithMatch(console.log,"[metric] "); }); it('default settings set to INFO and metrics off', function() { @@ -136,12 +137,12 @@ describe("@node-red/util/log", function() { log.debug("This is a debug"); log.trace("This is a trace"); log.log({level:log.METRIC,msg:"testMetric"}); - sinon.assert.calledWithMatch(util.log,"[error] This is an error"); - sinon.assert.calledWithMatch(util.log,"[warn] This is a warn"); - sinon.assert.calledWithMatch(util.log,"[info] This is an info"); - sinon.assert.neverCalledWithMatch(util.log,"[debug] This is a debug"); - sinon.assert.neverCalledWithMatch(util.log,"[trace] This is a trace"); - sinon.assert.neverCalledWithMatch(util.log,"[metric] "); + sinon.assert.calledWithMatch(console.log,"[error] This is an error"); + sinon.assert.calledWithMatch(console.log,"[warn] This is a warn"); + sinon.assert.calledWithMatch(console.log,"[info] This is an info"); + sinon.assert.neverCalledWithMatch(console.log,"[debug] This is a debug"); + sinon.assert.neverCalledWithMatch(console.log,"[trace] This is a trace"); + sinon.assert.neverCalledWithMatch(console.log,"[metric] "); }); it('no logger used if custom logger handler does not exist', function() { var settings = {logging: { customLogger: { level: 'trace', metrics: true } } }; @@ -152,12 +153,12 @@ describe("@node-red/util/log", function() { log.debug("This is a debug"); log.trace("This is a trace"); log.log({level:log.METRIC,msg:"testMetric"}); - sinon.assert.neverCalledWithMatch(util.log,"[error] This is an error"); - sinon.assert.neverCalledWithMatch(util.log,"[warn] This is a warn"); - sinon.assert.neverCalledWithMatch(util.log,"[info] This is an info"); - sinon.assert.neverCalledWithMatch(util.log,"[debug] This is a debug"); - sinon.assert.neverCalledWithMatch(util.log,"[trace] This is a trace"); - sinon.assert.neverCalledWithMatch(util.log,"[metric] "); + sinon.assert.neverCalledWithMatch(console.log,"[error] This is an error"); + sinon.assert.neverCalledWithMatch(console.log,"[warn] This is a warn"); + sinon.assert.neverCalledWithMatch(console.log,"[info] This is an info"); + sinon.assert.neverCalledWithMatch(console.log,"[debug] This is a debug"); + sinon.assert.neverCalledWithMatch(console.log,"[trace] This is a trace"); + sinon.assert.neverCalledWithMatch(console.log,"[metric] "); }); it('add a custom log handler directly', function() { @@ -244,7 +245,7 @@ describe("@node-red/util/log", function() { }, }; var ret = log.info(msg.msg); - sinon.assert.calledWithMatch(util.log,"my special message"); + sinon.assert.calledWithMatch(console.log,"my special message"); });