From bc283aa02507ea73e4b8186ad6d2ed7fff4c61f8 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Fri, 1 Nov 2019 11:38:26 +0000 Subject: [PATCH 1/7] Catches bad objects being encoded, returning instead the error. Symptom- Observed that global context would not display in front end, the call returning 400. Traced to an object in global which cause encodeObject to except. This push catches that, and now global will display, but the object in question display as an error. --- .../node_modules/@node-red/util/lib/util.js | 241 ++++++++++-------- 1 file changed, 128 insertions(+), 113 deletions(-) diff --git a/packages/node_modules/@node-red/util/lib/util.js b/packages/node_modules/@node-red/util/lib/util.js index 69ed930bb..d40a4de05 100644 --- a/packages/node_modules/@node-red/util/lib/util.js +++ b/packages/node_modules/@node-red/util/lib/util.js @@ -652,130 +652,145 @@ function normaliseNodeTypeName(name) { * @memberof @node-red/util_util */ function encodeObject(msg,opts) { - var debuglength = 1000; - if (opts && opts.hasOwnProperty('maxLength')) { - debuglength = opts.maxLength; - } - var msgType = typeof msg.msg; - if (msg.msg instanceof Error) { - msg.format = "error"; - var errorMsg = {}; - if (msg.msg.name) { - errorMsg.name = msg.msg.name; + try { + var debuglength = 1000; + if (opts && opts.hasOwnProperty('maxLength')) { + debuglength = opts.maxLength; } - if (msg.msg.hasOwnProperty('message')) { - errorMsg.message = msg.msg.message; - } else { - errorMsg.message = msg.msg.toString(); - } - msg.msg = JSON.stringify(errorMsg); - } else if (msg.msg instanceof Buffer) { - msg.format = "buffer["+msg.msg.length+"]"; - msg.msg = msg.msg.toString('hex'); - if (msg.msg.length > debuglength) { - msg.msg = msg.msg.substring(0,debuglength); - } - } else if (msg.msg && msgType === 'object') { - try { - msg.format = msg.msg.constructor.name || "Object"; - // Handle special case of msg.req/res objects from HTTP In node - if (msg.format === "IncomingMessage" || msg.format === "ServerResponse") { + var msgType = typeof msg.msg; + if (msg.msg instanceof Error) { + msg.format = "error"; + var errorMsg = {}; + if (msg.msg.name) { + errorMsg.name = msg.msg.name; + } + if (msg.msg.hasOwnProperty('message')) { + errorMsg.message = msg.msg.message; + } else { + errorMsg.message = msg.msg.toString(); + } + msg.msg = JSON.stringify(errorMsg); + } else if (msg.msg instanceof Buffer) { + msg.format = "buffer["+msg.msg.length+"]"; + msg.msg = msg.msg.toString('hex'); + if (msg.msg.length > debuglength) { + msg.msg = msg.msg.substring(0,debuglength); + } + } else if (msg.msg && msgType === 'object') { + try { + msg.format = msg.msg.constructor.name || "Object"; + // Handle special case of msg.req/res objects from HTTP In node + if (msg.format === "IncomingMessage" || msg.format === "ServerResponse") { + msg.format = "Object"; + } + } catch(err) { msg.format = "Object"; } - } catch(err) { - msg.format = "Object"; - } - if (/error/i.test(msg.format)) { - msg.msg = JSON.stringify({ - name: msg.msg.name, - message: msg.msg.message - }); - } else { - var isArray = util.isArray(msg.msg); - if (isArray) { - msg.format = "array["+msg.msg.length+"]"; - if (msg.msg.length > debuglength) { - // msg.msg = msg.msg.slice(0,debuglength); - msg.msg = { - __enc__: true, - type: "array", - data: msg.msg.slice(0,debuglength), - length: msg.msg.length - } - } - } - if (isArray || (msg.format === "Object")) { - msg.msg = safeJSONStringify(msg.msg, function(key, value) { - if (key === '_req' || key === '_res') { - value = { - __enc__: true, - type: "internal" - } - } else if (value instanceof Error) { - value = value.toString() - } else if (util.isArray(value) && value.length > debuglength) { - value = { + if (/error/i.test(msg.format)) { + msg.msg = JSON.stringify({ + name: msg.msg.name, + message: msg.msg.message + }); + } else { + var isArray = util.isArray(msg.msg); + if (isArray) { + msg.format = "array["+msg.msg.length+"]"; + if (msg.msg.length > debuglength) { + // msg.msg = msg.msg.slice(0,debuglength); + msg.msg = { __enc__: true, type: "array", - data: value.slice(0,debuglength), - length: value.length - } - } else if (typeof value === 'string') { - if (value.length > debuglength) { - value = value.substring(0,debuglength)+"..."; - } - } else if (typeof value === 'function') { - value = { - __enc__: true, - type: "function" - } - } else if (typeof value === 'number') { - if (isNaN(value) || value === Infinity || value === -Infinity) { - value = { - __enc__: true, - type: "number", - data: value.toString() - } - } - } else if (value && value.constructor) { - if (value.type === "Buffer") { - value.__enc__ = true; - value.length = value.data.length; - if (value.length > debuglength) { - value.data = value.data.slice(0,debuglength); - } - } else if (value.constructor.name === "ServerResponse") { - value = "[internal]" - } else if (value.constructor.name === "Socket") { - value = "[internal]" + data: msg.msg.slice(0,debuglength), + length: msg.msg.length } } - return value; - }," "); - } else { - try { msg.msg = msg.msg.toString(); } - catch(e) { msg.msg = "[Type not printable]"; } + } + if (isArray || (msg.format === "Object")) { + msg.msg = safeJSONStringify(msg.msg, function(key, value) { + if (key === '_req' || key === '_res') { + value = { + __enc__: true, + type: "internal" + } + } else if (value instanceof Error) { + value = value.toString() + } else if (util.isArray(value) && value.length > debuglength) { + value = { + __enc__: true, + type: "array", + data: value.slice(0,debuglength), + length: value.length + } + } else if (typeof value === 'string') { + if (value.length > debuglength) { + value = value.substring(0,debuglength)+"..."; + } + } else if (typeof value === 'function') { + value = { + __enc__: true, + type: "function" + } + } else if (typeof value === 'number') { + if (isNaN(value) || value === Infinity || value === -Infinity) { + value = { + __enc__: true, + type: "number", + data: value.toString() + } + } + } else if (value && value.constructor) { + if (value.type === "Buffer") { + value.__enc__ = true; + value.length = value.data.length; + if (value.length > debuglength) { + value.data = value.data.slice(0,debuglength); + } + } else if (value.constructor.name === "ServerResponse") { + value = "[internal]" + } else if (value.constructor.name === "Socket") { + value = "[internal]" + } + } + return value; + }," "); + } else { + try { msg.msg = msg.msg.toString(); } + catch(e) { msg.msg = "[Type not printable]"; } + } + } + } else if (msgType === "function") { + msg.format = "function"; + msg.msg = "[function]" + } else if (msgType === "boolean") { + msg.format = "boolean"; + msg.msg = msg.msg.toString(); + } else if (msgType === "number") { + msg.format = "number"; + msg.msg = msg.msg.toString(); + } else if (msg.msg === null || msgType === "undefined") { + msg.format = (msg.msg === null)?"null":"undefined"; + msg.msg = "(undefined)"; + } else { + msg.format = "string["+msg.msg.length+"]"; + if (msg.msg.length > debuglength) { + msg.msg = msg.msg.substring(0,debuglength)+"..."; } } - } else if (msgType === "function") { - msg.format = "function"; - msg.msg = "[function]" - } else if (msgType === "boolean") { - msg.format = "boolean"; - msg.msg = msg.msg.toString(); - } else if (msgType === "number") { - msg.format = "number"; - msg.msg = msg.msg.toString(); - } else if (msg.msg === null || msgType === "undefined") { - msg.format = (msg.msg === null)?"null":"undefined"; - msg.msg = "(undefined)"; - } else { - msg.format = "string["+msg.msg.length+"]"; - if (msg.msg.length > debuglength) { - msg.msg = msg.msg.substring(0,debuglength)+"..."; + return msg; + } catch(e) { + msg.format = "error"; + var errorMsg = {}; + if (e.name) { + errorMsg.name = e.name; } + if (e.hasOwnProperty('message')) { + errorMsg.message = e.message; + } else { + errorMsg.message = e.toString(); + } + msg.msg = JSON.stringify(errorMsg); + return msg; } - return msg; } module.exports = { From eb09ec6834e1c8600cc0c8bc5212ef5ba451dc16 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 10:39:22 +0000 Subject: [PATCH 2/7] add utils.inspect result and be more explicit about the error. --- packages/node_modules/@node-red/util/lib/util.js | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/packages/node_modules/@node-red/util/lib/util.js b/packages/node_modules/@node-red/util/lib/util.js index d40a4de05..df7c404b0 100644 --- a/packages/node_modules/@node-red/util/lib/util.js +++ b/packages/node_modules/@node-red/util/lib/util.js @@ -784,9 +784,12 @@ function encodeObject(msg,opts) { errorMsg.name = e.name; } if (e.hasOwnProperty('message')) { - errorMsg.message = e.message; + errorMsg.message = 'encodeObject Error: ['+e.message + '] Value: '+util.inspect(msg.msg); } else { - errorMsg.message = e.toString(); + errorMsg.message = 'encodeObject Error: ['+e.toString() + '] Value: '+util.inspect(msg.msg); + } + if (errorMsg.message.length > debuglength) { + errorMsg.message = errorMsg.message.substring(0,debuglength); } msg.msg = JSON.stringify(errorMsg); return msg; From d46531def82ea60a16e330f38b9f830cab566d86 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 11:27:08 +0000 Subject: [PATCH 3/7] add unit tests for encode Object changes. --- test/unit/@node-red/util/lib/util_spec.js | 51 +++++++++++++++++++++++ 1 file changed, 51 insertions(+) diff --git a/test/unit/@node-red/util/lib/util_spec.js b/test/unit/@node-red/util/lib/util_spec.js index 17304e811..603f4524c 100644 --- a/test/unit/@node-red/util/lib/util_spec.js +++ b/test/unit/@node-red/util/lib/util_spec.js @@ -772,6 +772,57 @@ describe("@node-red/util/util", function() { var resultJson = JSON.parse(result.msg); resultJson.socket.should.eql('[internal]'); }); + it('object which fails to serialise', function(done) { + var msg = { + msg: { + obj:{ + cantserialise:{ + message:'this will not be displayed', + toJSON: function(val) { + throw 'this exception should have been caught'; + return 'should not display because we threw first'; + }, + }, + canserialise:{ + message:'this should be displayed', + } + }, + } + }; + var result = util.encodeObject(msg); + result.format.should.eql("error"); + var success = (result.msg.indexOf('cantserialise') > 0); + success &= (result.msg.indexOf('this exception should have been caught') > 0); + success &= (result.msg.indexOf('canserialise') > 0); + success.should.eql(1); + done(); + }); + it('object which fails to serialise - different error type', function(done) { + var msg = { + msg: { + obj:{ + cantserialise:{ + message:'this will not be displayed', + toJSON: function(val) { + throw new Error('this exception should have been caught'); + return 'should not display because we threw first'; + }, + }, + canserialise:{ + message:'this should be displayed', + } + }, + } + }; + var result = util.encodeObject(msg); + result.format.should.eql("error"); + var success = (result.msg.indexOf('cantserialise') > 0); + success &= (result.msg.indexOf('this exception should have been caught') > 0); + success &= (result.msg.indexOf('canserialise') > 0); + success.should.eql(1); + done(); + }); + }); }); }); From 74d760a46d395e77a4991a9d9843e6f1b5f63dd5 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 12:37:07 +0000 Subject: [PATCH 4/7] add util.inspect data to 'type not printable'. Add test to cover these lines (no existing test). --- .../node_modules/@node-red/util/lib/util.js | 2 +- test/unit/@node-red/util/lib/util_spec.js | 47 +++++++++++++++++++ 2 files changed, 48 insertions(+), 1 deletion(-) diff --git a/packages/node_modules/@node-red/util/lib/util.js b/packages/node_modules/@node-red/util/lib/util.js index df7c404b0..ef43739e6 100644 --- a/packages/node_modules/@node-red/util/lib/util.js +++ b/packages/node_modules/@node-red/util/lib/util.js @@ -755,7 +755,7 @@ function encodeObject(msg,opts) { }," "); } else { try { msg.msg = msg.msg.toString(); } - catch(e) { msg.msg = "[Type not printable]"; } + catch(e) { msg.msg = "[Type not printable]" + util.inspect(msg.msg); } } } } else if (msgType === "function") { diff --git a/test/unit/@node-red/util/lib/util_spec.js b/test/unit/@node-red/util/lib/util_spec.js index 603f4524c..b3f9fe57d 100644 --- a/test/unit/@node-red/util/lib/util_spec.js +++ b/test/unit/@node-red/util/lib/util_spec.js @@ -822,6 +822,53 @@ describe("@node-red/util/util", function() { success.should.eql(1); done(); }); + it('very large object which fails to serialise should be truncated', function(done) { + var msg = { + msg: { + obj:{ + big:"", + cantserialise:{ + message:'this will not be displayed', + toJSON: function(val) { + throw new Error('this exception should have been caught'); + return 'should not display because we threw first'; + }, + }, + canserialise:{ + message:'this should be displayed', + } + }, + } + }; + + for (var i = 0; i < 1000; i++) { + msg.msg.obj.big += 'some more string '; + } + + var result = util.encodeObject(msg); + result.format.should.eql("error"); + var resultJson = JSON.parse(result.msg); + var success = (resultJson.message.length <= 1000); + success.should.eql(true); + done(); + }); + it('test bad toString', function(done) { + var msg = { + msg: { + mystrangeobj:"hello", + }, + }; + msg.msg.toString = function(){ + throw new Error('Exception in toString - should have been caught'); + } + msg.msg.constructor = { name: "strangeobj" }; + + var result = util.encodeObject(msg); + var success = (result.msg.indexOf('[Type not printable]') >= 0); + success.should.eql(true); + done(); + }); + }); }); From 63cc9adeaa98bae3d4ad60270b108d2ada8355a0 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 12:38:40 +0000 Subject: [PATCH 5/7] small update to log - if toString() causes exception, then note and use util.inspect instead - prevents log from causing processes to abort through exception. Add tests. --- packages/node_modules/@node-red/util/lib/log.js | 9 +++++++-- test/unit/@node-red/util/lib/log_spec.js | 14 ++++++++++++++ 2 files changed, 21 insertions(+), 2 deletions(-) diff --git a/packages/node_modules/@node-red/util/lib/log.js b/packages/node_modules/@node-red/util/lib/log.js index 155863802..8d7b84966 100644 --- a/packages/node_modules/@node-red/util/lib/log.js +++ b/packages/node_modules/@node-red/util/lib/log.js @@ -84,9 +84,14 @@ var consoleLogger = function(msg) { util.log("["+levelNames[msg.level]+"] "+(msg.type?"["+msg.type+":"+(msg.name||msg.id)+"] ":"")+msg.msg.stack); } else { var message = msg.msg; - if (typeof message === 'object' && message !== null && message.toString() === '[object Object]' && message.message) { - message = message.message; + try { + if (typeof message === 'object' && message !== null && message.toString() === '[object Object]' && message.message) { + message = message.message; + } + } catch(e){ + message = 'Exception trying to log: '+util.inspect(message); } + util.log("["+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 9a6f1ac28..73df7d620 100644 --- a/test/unit/@node-red/util/lib/log_spec.js +++ b/test/unit/@node-red/util/lib/log_spec.js @@ -224,5 +224,19 @@ describe("@node-red/util/log", function() { }); + it('it can log without exception', function() { + var msg = { + msg: { + mystrangeobj:"hello", + }, + }; + msg.msg.toString = function(){ + throw new Error('Exception in toString - should have been caught'); + } + msg.msg.constructor = { name: "strangeobj" }; + var ret = log.info(msg.msg); + }); + + }); From c54509df3d31f8a4808bda23d27946c734e70bff Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 13:03:37 +0000 Subject: [PATCH 6/7] additional test to cover last line in encodeObject --- test/unit/@node-red/util/lib/util_spec.js | 21 +++++++++++++++++---- 1 file changed, 17 insertions(+), 4 deletions(-) diff --git a/test/unit/@node-red/util/lib/util_spec.js b/test/unit/@node-red/util/lib/util_spec.js index b3f9fe57d..cf59df55e 100644 --- a/test/unit/@node-red/util/lib/util_spec.js +++ b/test/unit/@node-red/util/lib/util_spec.js @@ -842,7 +842,7 @@ describe("@node-red/util/util", function() { }; for (var i = 0; i < 1000; i++) { - msg.msg.obj.big += 'some more string '; + msg.msg.obj.big += 'some more string '; } var result = util.encodeObject(msg); @@ -855,11 +855,11 @@ describe("@node-red/util/util", function() { it('test bad toString', function(done) { var msg = { msg: { - mystrangeobj:"hello", + mystrangeobj:"hello", }, }; msg.msg.toString = function(){ - throw new Error('Exception in toString - should have been caught'); + throw new Error('Exception in toString - should have been caught'); } msg.msg.constructor = { name: "strangeobj" }; @@ -868,8 +868,21 @@ describe("@node-red/util/util", function() { success.should.eql(true); done(); }); + it('test bad object constructor', function(done) { + var msg = { + msg: { + mystrangeobj:"hello", + constructor: { + get name(){ + throw new Error('Exception in constructor name'); + } + } + }, + }; + var result = util.encodeObject(msg); + done(); + }); - }); }); }); From 5e9e523d4c63b4ec8b969a8169a4ee742532db76 Mon Sep 17 00:00:00 2001 From: Simon Hailes Date: Sat, 2 Nov 2019 13:21:58 +0000 Subject: [PATCH 7/7] add one line of coverage in log tests. --- test/unit/@node-red/util/lib/log_spec.js | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/test/unit/@node-red/util/lib/log_spec.js b/test/unit/@node-red/util/lib/log_spec.js index 73df7d620..c882dd2ae 100644 --- a/test/unit/@node-red/util/lib/log_spec.js +++ b/test/unit/@node-red/util/lib/log_spec.js @@ -236,6 +236,16 @@ describe("@node-red/util/log", function() { msg.msg.constructor = { name: "strangeobj" }; var ret = log.info(msg.msg); }); + it('it can log an object but use .message', function() { + var msg = { + msg: { + message: "my special message", + mystrangeobj:"hello", + }, + }; + var ret = log.info(msg.msg); + sinon.assert.calledWithMatch(util.log,"my special message"); + });