From 995c7626a9e19732aeae0ea1226c9ca75f0e4b7e Mon Sep 17 00:00:00 2001 From: Martin Date: Fri, 18 Oct 2019 06:49:59 +0200 Subject: [PATCH 1/5] initial contribution core/log.js --- Core/automation/lib/javascript/core/log.js | 199 +++++++++++++++++++ Core/automation/lib/javascript/core/utils.js | 28 +-- 2 files changed, 214 insertions(+), 13 deletions(-) create mode 100644 Core/automation/lib/javascript/core/log.js diff --git a/Core/automation/lib/javascript/core/log.js b/Core/automation/lib/javascript/core/log.js new file mode 100644 index 00000000..6636519f --- /dev/null +++ b/Core/automation/lib/javascript/core/log.js @@ -0,0 +1,199 @@ +/** + * Logging functions and variables + * + * Copyright (c) 2019 Contributors to the openHAB Scripters project + * + * @author Martin Stangl - initial contribution + */ +'use strict'; + +(function context (context) { + 'use strict'; + + load(__DIR__+'/actions.js'); + + context.NOTIFY_OFF = 0; + context.NOTIFY_ERROR = 200; + context.NOTIFY_WARN = 300; + context.NOTIFY_INFO = 400; + context.NOTIFY_DEBUG = 500; + + context.Logger = function Logger (name, notificationLevel, config) { + if (name === undefined) { + name = Error().stack.split('\n')[2].split('/').slice(-2).join('.').split(':')[0]; + name = name.slice(-3) == ".js" ? name.slice(0,-3) : null; + } + var _logger = Java.type("org.slf4j.LoggerFactory").getLogger(name === null ? "jsr223.javascript" : "jsr223.javascript." + name.toString().toLowerCase()); + + try { + // Set default config for config params not provided. + if (config === undefined) config = {}; + if (config.ERROR === undefined) config.ERROR = {}; + if (config.WARN === undefined) config.WARN = {}; + if (config.INFO === undefined) config.INFO = {}; + if (config.DEBUG === undefined) config.DEBUG = {}; + if (config.ERROR.prefix === undefined) config.ERROR.prefix = "short"; + if (config.WARN.prefix === undefined) config.WARN.prefix = "none"; + if (config.INFO.prefix === undefined) config.INFO.prefix = "none"; + if (config.DEBUG.prefix === undefined) config.DEBUG.prefix = "short"; + + return Object.create(Object.prototype, { + _notificationLevel: { value: (notificationLevel === undefined || notificationLevel === null) ? context.NOTIFY_OFF : notificationLevel }, + _config: { value: config }, + _name: { value: name }, + + error: { value: function error (msg) { + try { + if (_logger.isErrorEnabled()) { + eval("_logger.error" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + } + if (this._notificationLevel >= context.NOTIFY_ERROR) { + this._sendNotification(this._getLogMessage(msg, this._config.ERROR.prefix, "ERROR"), "fire", "ERROR"); + } + } catch (err) { + _logger.error(this._getLogMessage(err)); + } + }}, + + warn: { value: function warn (msg) { + try { + if (_logger.isWarnEnabled()) { + eval("_logger.warn" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + } + if (this._notificationLevel >= context.NOTIFY_WARN) { + this._sendNotification(this._getLogMessage(msg, this._config.WARN.prefix, "WARN"), "error", "WARN"); + } + } catch (err) { + _logger.error(this._getLogMessage(err)); + } + }}, + + info: { value: function info (msg) { + try { + if (_logger.isInfoEnabled()) { + eval("_logger.info" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + } + if (this._notificationLevel >= context.NOTIFY_INFO) { + this._sendNotification(this._getLogMessage(msg, this._config.INFO.prefix, "INFO"), "lightbulb", "INFO"); + } + } catch (err) { + _logger.error(this._getLogMessage(err)); + } + }}, + + debug: { value: function debug (msg) { + try { + if (_logger.isDebugEnabled()) { + eval("_logger.debug" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + } + if (this._notificationLevel >= context.NOTIFY_DEBUG) { + this._sendNotification(this._getLogMessage(msg, this._config.DEBUG.prefix, "DEBUG"), "text", "DEBUG"); + } + } catch (err) { + _logger.error(this._getLogMessage(err)); + } + }}, + + trace: { value: function trace (msg) { + try { + if (_logger.isTraceEnabled()) { + eval("_logger.trace" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + } + } catch (err) { + _logger.error(this._getLogMessage(err)); + } + }}, + + _getCaller: { value: function _getCaller (stack) { + try { + return stack.split('\n\tat ')[1].split(' ')[0]; + } catch (err) { + return null; + } + }}, + + _getLogMessage: { value: function _getLogMessage (msg, prefix, levelString) { + msg = this._legacyLoggerCorrection(msg); + + if (prefix === undefined) prefix = "log"; + + if (prefix == "none") { + return msg.message; + } + + var level = ""; + var name = ""; + if (prefix != "log") { + level = "[" + levelString + "] "; + name = this._name === null ? "" : this._name + ": "; + } + + if (prefix == "level") { + return (level + msg.message); + } + + var caller = this._getCaller(msg.stack); + var callerText; + if (caller === null) { + callerText = ""; + } else if (caller.substr(0,1) == "<") { + callerText = ", in " + caller; + } else { + callerText = ", function " + caller; + } + var message = msg.message == "" ? "" : "] " + msg.message; + + if (prefix == "short") { + return (level + "[" + name + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + message); + } + + return (level + "[" + name + "source " + msg.fileName + ", line " + msg.lineNumber + callerText + message); + }}, + + _legacyLoggerCorrection: { value: function _legacyLoggerCorrection (msg) { + if (msg.fileName.search(/automation\/lib\/javascript\/core\/utils\.js$/) !== -1) { + switch (this._getCaller(msg.stack)) { + case "logError": + case "logWarn": + case "logInfo": + case "logDebug": + case "logTrace": + case "log": + msg.stack = msg.stack.split('\n\tat ').slice(1).join('\n\tat '); + msg.fileName = msg.stack.split('\n\tat ')[1].match(/.*? \((.*):/)[1]; + msg.lineNumber = msg.stack.split('\n\tat ')[1].match(/.*:(.*?)\)/)[1]; + } + } + return msg; + }}, + + _sendNotification: { value: function _sendNotification (message, icon, levelString) { + if (this._config[levelString].recipients !== undefined) { + this._config[levelString].recipients.forEach(function(mail){ + NotificationAction.sendNotification(mail, message, icon, levelString); + }) + if (this._config[levelString].recipients.length > 0) { + this.trace(Error("Notification sent to " + this._config[levelString].recipients.join(", ") + ". Message: \"" + message + "\"")); + } + } else { + NotificationAction.sendBroadcastNotification(message, icon, levelString); + this.trace(Error("Broadcast notification sent. Message: \"" + message + "\"")); + } + }}, + + _loggerArgs: { value: function _loggerArgs (msg, length) { + var str = "(\"" + msg.replace(/\n/g, '\\n') + "\""; + for (var i = 1; i < length; i++) { + str = str+",arguments["+i+"]"; + } + str = str+");" + return str; + }} + + }) + } catch (err) { + _logger.error(err.fileName + ", line " + err.lineNumber + ": " + err.message); + } + } + +})(this); \ No newline at end of file diff --git a/Core/automation/lib/javascript/core/utils.js b/Core/automation/lib/javascript/core/utils.js index 0fc3e984..a863624a 100644 --- a/Core/automation/lib/javascript/core/utils.js +++ b/Core/automation/lib/javascript/core/utils.js @@ -11,7 +11,9 @@ var automationPath = OPENHAB_CONF+'/automation/'; var mainPath = automationPath + 'lib/javascript/core/'; //https://wiki.shibboleth.net/confluence/display/IDP30/ScriptedAttributeDefinition - var logger = Java.type("org.slf4j.LoggerFactory").getLogger("jsr223.javascript"); + + load(__DIR__+'/log.js'); + var logger = Logger(null); try { var RuleBuilder = Java.type("org.openhab.core.automation.util.RuleBuilder"); @@ -87,20 +89,20 @@ context.uuid = uuid; - context.logInfo = function(type , value) { - logger.info(args(arguments)); + context.logInfo = function (type , value) { + logger.info(Error(args(arguments))); }; - context.logWarn = function(type , value) { - logger.warn(args(arguments)); + context.logWarn = function (type , value) { + logger.warn(Error(args(arguments))); }; - context.logDebug = function(type , value) { - logger.debug(args(arguments)); + context.logDebug = function (type , value) { + logger.debug(Error(args(arguments))); }; - context.logError = function(type , value) { - logger.error(args(arguments)); + context.logError = function (type , value) { + logger.error(Error(args(arguments))); }; - context.logTrace = function(type , value) { - logger.trace(args(arguments)); + context.logTrace = function (type , value) { + logger.trace(Error(args(arguments))); }; @@ -110,8 +112,8 @@ context.console.debug = context.logDebug; context.console.error = context.logError; - context.console.log = function(value) { - logger.info("console.log", value); + context.console.log = function (value) { + logger.info(Error("console.log"), value); }; context.isUndefined = function(item) { From f25bf6152d32b8cf124405bb4d67da441e2e4dc5 Mon Sep 17 00:00:00 2001 From: Martin Date: Sat, 19 Oct 2019 04:04:14 +0200 Subject: [PATCH 2/5] log string added, fixed parameterization for notifications, legacy console log functions improved/fixed --- Core/automation/lib/javascript/core/log.js | 94 ++++++++++---------- Core/automation/lib/javascript/core/utils.js | 29 +++--- 2 files changed, 66 insertions(+), 57 deletions(-) diff --git a/Core/automation/lib/javascript/core/log.js b/Core/automation/lib/javascript/core/log.js index 6636519f..98986d13 100644 --- a/Core/automation/lib/javascript/core/log.js +++ b/Core/automation/lib/javascript/core/log.js @@ -24,6 +24,7 @@ name = name.slice(-3) == ".js" ? name.slice(0,-3) : null; } var _logger = Java.type("org.slf4j.LoggerFactory").getLogger(name === null ? "jsr223.javascript" : "jsr223.javascript." + name.toString().toLowerCase()); + var _messageFormatter = Java.type("org.slf4j.helpers.MessageFormatter"); try { // Set default config for config params not provided. @@ -44,11 +45,11 @@ error: { value: function error (msg) { try { - if (_logger.isErrorEnabled()) { - eval("_logger.error" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + if (_logger.isErrorEnabled()) { + _logger.error(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); } if (this._notificationLevel >= context.NOTIFY_ERROR) { - this._sendNotification(this._getLogMessage(msg, this._config.ERROR.prefix, "ERROR"), "fire", "ERROR"); + this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.ERROR.prefix, "ERROR"), [].slice.call(arguments).slice(1)).getMessage(), "fire", "ERROR"); } } catch (err) { _logger.error(this._getLogMessage(err)); @@ -58,10 +59,10 @@ warn: { value: function warn (msg) { try { if (_logger.isWarnEnabled()) { - eval("_logger.warn" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + _logger.warn(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); } if (this._notificationLevel >= context.NOTIFY_WARN) { - this._sendNotification(this._getLogMessage(msg, this._config.WARN.prefix, "WARN"), "error", "WARN"); + this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.WARN.prefix, "WARN"), [].slice.call(arguments).slice(1)).getMessage(), "error", "WARN"); } } catch (err) { _logger.error(this._getLogMessage(err)); @@ -71,10 +72,10 @@ info: { value: function info (msg) { try { if (_logger.isInfoEnabled()) { - eval("_logger.info" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + _logger.info(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); } if (this._notificationLevel >= context.NOTIFY_INFO) { - this._sendNotification(this._getLogMessage(msg, this._config.INFO.prefix, "INFO"), "lightbulb", "INFO"); + this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.INFO.prefix, "INFO"), [].slice.call(arguments).slice(1)).getMessage(), "lightbulb", "INFO"); } } catch (err) { _logger.error(this._getLogMessage(err)); @@ -84,10 +85,10 @@ debug: { value: function debug (msg) { try { if (_logger.isDebugEnabled()) { - eval("_logger.debug" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + _logger.debug(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); } if (this._notificationLevel >= context.NOTIFY_DEBUG) { - this._sendNotification(this._getLogMessage(msg, this._config.DEBUG.prefix, "DEBUG"), "text", "DEBUG"); + this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.DEBUG.prefix, "DEBUG"), [].slice.call(arguments).slice(1)).getMessage(), "text", "DEBUG"); } } catch (err) { _logger.error(this._getLogMessage(err)); @@ -96,23 +97,29 @@ trace: { value: function trace (msg) { try { - if (_logger.isTraceEnabled()) { - eval("_logger.trace" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); + if (_logger.isTraceEnabled()) { + _logger.trace(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); } } catch (err) { _logger.error(this._getLogMessage(err)); } }}, - - _getCaller: { value: function _getCaller (stack) { - try { - return stack.split('\n\tat ')[1].split(' ')[0]; - } catch (err) { - return null; - } - }}, - + + _getCallerDetails: { value: function _getCallerDetails (msg) { + var matches = msg.stack.split('\n\tat ')[3].match(/(.+?) \((.+):(\d+?)\)/); + msg.caller = matches[1]; + msg.fileName = matches[2] + msg.lineNumber = matches[3] + return msg; + }}, + _getLogMessage: { value: function _getLogMessage (msg, prefix, levelString) { + if ((typeof msg) !== "object") { + msg = Error(msg); + msg = this._getCallerDetails(msg); + } else { + msg.caller = msg.stack.split('\n\tat ')[1].split(' (')[0] + } msg = this._legacyLoggerCorrection(msg); if (prefix === undefined) prefix = "log"; @@ -125,44 +132,46 @@ var name = ""; if (prefix != "log") { level = "[" + levelString + "] "; - name = this._name === null ? "" : this._name + ": "; + name = this._name === null ? "" : this._name; } if (prefix == "level") { - return (level + msg.message); + return (level + msg); } - var caller = this._getCaller(msg.stack); var callerText; - if (caller === null) { - callerText = ""; - } else if (caller.substr(0,1) == "<") { - callerText = ", in " + caller; + if (msg.caller.substr(0,1) == "<") { + callerText = ", in " + msg.caller; } else { - callerText = ", function " + caller; + callerText = ", function " + msg.caller; } + var message = msg.message == "" ? "" : "] " + msg.message; if (prefix == "short") { - return (level + "[" + name + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + message); + return (level + "[" + (name != "" ? name + ", " : "") + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + message); } - - return (level + "[" + name + "source " + msg.fileName + ", line " + msg.lineNumber + callerText + message); + return (level + "[" + (name != "" ? name + ": " : "") + "source " + msg.fileName + ", line " + msg.lineNumber + callerText + message); }}, _legacyLoggerCorrection: { value: function _legacyLoggerCorrection (msg) { if (msg.fileName.search(/automation\/lib\/javascript\/core\/utils\.js$/) !== -1) { - switch (this._getCaller(msg.stack)) { + switch (msg.caller) { case "logError": case "logWarn": case "logInfo": case "logDebug": - case "logTrace": - case "log": - msg.stack = msg.stack.split('\n\tat ').slice(1).join('\n\tat '); - msg.fileName = msg.stack.split('\n\tat ')[1].match(/.*? \((.*):/)[1]; - msg.lineNumber = msg.stack.split('\n\tat ')[1].match(/.*:(.*?)\)/)[1]; - } + case "logTrace": + case "error": + case "warn": + case "info": + case "debug": + case "log": + var stackArray = msg.stack.split('\n\tat '); + stackArray.splice(3,1); + msg.stack = stackArray.join('\n\tat '); + msg = this._getCallerDetails(msg); + } } return msg; }}, @@ -179,15 +188,6 @@ NotificationAction.sendBroadcastNotification(message, icon, levelString); this.trace(Error("Broadcast notification sent. Message: \"" + message + "\"")); } - }}, - - _loggerArgs: { value: function _loggerArgs (msg, length) { - var str = "(\"" + msg.replace(/\n/g, '\\n') + "\""; - for (var i = 1; i < length; i++) { - str = str+",arguments["+i+"]"; - } - str = str+");" - return str; }} }) diff --git a/Core/automation/lib/javascript/core/utils.js b/Core/automation/lib/javascript/core/utils.js index a863624a..e720b1ad 100644 --- a/Core/automation/lib/javascript/core/utils.js +++ b/Core/automation/lib/javascript/core/utils.js @@ -14,6 +14,7 @@ load(__DIR__+'/log.js'); var logger = Logger(null); + var loggerConsole = Logger("console"); try { var RuleBuilder = Java.type("org.openhab.core.automation.util.RuleBuilder"); @@ -90,30 +91,38 @@ context.uuid = uuid; context.logInfo = function (type , value) { - logger.info(Error(args(arguments))); + logger.info(args(arguments)); }; context.logWarn = function (type , value) { - logger.warn(Error(args(arguments))); + logger.warn(args(arguments)); }; context.logDebug = function (type , value) { - logger.debug(Error(args(arguments))); + logger.debug(args(arguments)); }; context.logError = function (type , value) { - logger.error(Error(args(arguments))); + logger.error(args(arguments)); }; context.logTrace = function (type , value) { - logger.trace(Error(args(arguments))); + logger.trace(args(arguments)); }; context.console = {}; - context.console.info = context.logInfo; - context.console.warn = context.logWarn; - context.console.debug = context.logDebug; - context.console.error = context.logError; + context.console.info = function (type , value) { + loggerConsole.info(args(arguments)); + }; + context.console.warn = function (type , value) { + loggerConsole.warn(args(arguments)); + }; + context.console.debug = function (type , value) { + loggerConsole.debug(args(arguments)); + }; + context.console.error = function (type , value) { + loggerConsole.error(args(arguments)); + }; context.console.log = function (value) { - logger.info(Error("console.log"), value); + loggerConsole.info(value.toString()); }; context.isUndefined = function(item) { From 91a89a0fdf0fc191b2315044dd85bed4bb380f6c Mon Sep 17 00:00:00 2001 From: Martin Date: Sat, 19 Oct 2019 04:47:36 +0200 Subject: [PATCH 3/5] Revert master back to upstream state. --- Core/automation/lib/javascript/core/log.js | 199 ------------------- Core/automation/lib/javascript/core/utils.js | 28 ++- 2 files changed, 13 insertions(+), 214 deletions(-) delete mode 100644 Core/automation/lib/javascript/core/log.js diff --git a/Core/automation/lib/javascript/core/log.js b/Core/automation/lib/javascript/core/log.js deleted file mode 100644 index 6636519f..00000000 --- a/Core/automation/lib/javascript/core/log.js +++ /dev/null @@ -1,199 +0,0 @@ -/** - * Logging functions and variables - * - * Copyright (c) 2019 Contributors to the openHAB Scripters project - * - * @author Martin Stangl - initial contribution - */ -'use strict'; - -(function context (context) { - 'use strict'; - - load(__DIR__+'/actions.js'); - - context.NOTIFY_OFF = 0; - context.NOTIFY_ERROR = 200; - context.NOTIFY_WARN = 300; - context.NOTIFY_INFO = 400; - context.NOTIFY_DEBUG = 500; - - context.Logger = function Logger (name, notificationLevel, config) { - if (name === undefined) { - name = Error().stack.split('\n')[2].split('/').slice(-2).join('.').split(':')[0]; - name = name.slice(-3) == ".js" ? name.slice(0,-3) : null; - } - var _logger = Java.type("org.slf4j.LoggerFactory").getLogger(name === null ? "jsr223.javascript" : "jsr223.javascript." + name.toString().toLowerCase()); - - try { - // Set default config for config params not provided. - if (config === undefined) config = {}; - if (config.ERROR === undefined) config.ERROR = {}; - if (config.WARN === undefined) config.WARN = {}; - if (config.INFO === undefined) config.INFO = {}; - if (config.DEBUG === undefined) config.DEBUG = {}; - if (config.ERROR.prefix === undefined) config.ERROR.prefix = "short"; - if (config.WARN.prefix === undefined) config.WARN.prefix = "none"; - if (config.INFO.prefix === undefined) config.INFO.prefix = "none"; - if (config.DEBUG.prefix === undefined) config.DEBUG.prefix = "short"; - - return Object.create(Object.prototype, { - _notificationLevel: { value: (notificationLevel === undefined || notificationLevel === null) ? context.NOTIFY_OFF : notificationLevel }, - _config: { value: config }, - _name: { value: name }, - - error: { value: function error (msg) { - try { - if (_logger.isErrorEnabled()) { - eval("_logger.error" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); - } - if (this._notificationLevel >= context.NOTIFY_ERROR) { - this._sendNotification(this._getLogMessage(msg, this._config.ERROR.prefix, "ERROR"), "fire", "ERROR"); - } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - warn: { value: function warn (msg) { - try { - if (_logger.isWarnEnabled()) { - eval("_logger.warn" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); - } - if (this._notificationLevel >= context.NOTIFY_WARN) { - this._sendNotification(this._getLogMessage(msg, this._config.WARN.prefix, "WARN"), "error", "WARN"); - } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - info: { value: function info (msg) { - try { - if (_logger.isInfoEnabled()) { - eval("_logger.info" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); - } - if (this._notificationLevel >= context.NOTIFY_INFO) { - this._sendNotification(this._getLogMessage(msg, this._config.INFO.prefix, "INFO"), "lightbulb", "INFO"); - } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - debug: { value: function debug (msg) { - try { - if (_logger.isDebugEnabled()) { - eval("_logger.debug" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); - } - if (this._notificationLevel >= context.NOTIFY_DEBUG) { - this._sendNotification(this._getLogMessage(msg, this._config.DEBUG.prefix, "DEBUG"), "text", "DEBUG"); - } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - trace: { value: function trace (msg) { - try { - if (_logger.isTraceEnabled()) { - eval("_logger.trace" + this._loggerArgs(this._getLogMessage(msg), arguments.length)); - } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - _getCaller: { value: function _getCaller (stack) { - try { - return stack.split('\n\tat ')[1].split(' ')[0]; - } catch (err) { - return null; - } - }}, - - _getLogMessage: { value: function _getLogMessage (msg, prefix, levelString) { - msg = this._legacyLoggerCorrection(msg); - - if (prefix === undefined) prefix = "log"; - - if (prefix == "none") { - return msg.message; - } - - var level = ""; - var name = ""; - if (prefix != "log") { - level = "[" + levelString + "] "; - name = this._name === null ? "" : this._name + ": "; - } - - if (prefix == "level") { - return (level + msg.message); - } - - var caller = this._getCaller(msg.stack); - var callerText; - if (caller === null) { - callerText = ""; - } else if (caller.substr(0,1) == "<") { - callerText = ", in " + caller; - } else { - callerText = ", function " + caller; - } - var message = msg.message == "" ? "" : "] " + msg.message; - - if (prefix == "short") { - return (level + "[" + name + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + message); - } - - return (level + "[" + name + "source " + msg.fileName + ", line " + msg.lineNumber + callerText + message); - }}, - - _legacyLoggerCorrection: { value: function _legacyLoggerCorrection (msg) { - if (msg.fileName.search(/automation\/lib\/javascript\/core\/utils\.js$/) !== -1) { - switch (this._getCaller(msg.stack)) { - case "logError": - case "logWarn": - case "logInfo": - case "logDebug": - case "logTrace": - case "log": - msg.stack = msg.stack.split('\n\tat ').slice(1).join('\n\tat '); - msg.fileName = msg.stack.split('\n\tat ')[1].match(/.*? \((.*):/)[1]; - msg.lineNumber = msg.stack.split('\n\tat ')[1].match(/.*:(.*?)\)/)[1]; - } - } - return msg; - }}, - - _sendNotification: { value: function _sendNotification (message, icon, levelString) { - if (this._config[levelString].recipients !== undefined) { - this._config[levelString].recipients.forEach(function(mail){ - NotificationAction.sendNotification(mail, message, icon, levelString); - }) - if (this._config[levelString].recipients.length > 0) { - this.trace(Error("Notification sent to " + this._config[levelString].recipients.join(", ") + ". Message: \"" + message + "\"")); - } - } else { - NotificationAction.sendBroadcastNotification(message, icon, levelString); - this.trace(Error("Broadcast notification sent. Message: \"" + message + "\"")); - } - }}, - - _loggerArgs: { value: function _loggerArgs (msg, length) { - var str = "(\"" + msg.replace(/\n/g, '\\n') + "\""; - for (var i = 1; i < length; i++) { - str = str+",arguments["+i+"]"; - } - str = str+");" - return str; - }} - - }) - } catch (err) { - _logger.error(err.fileName + ", line " + err.lineNumber + ": " + err.message); - } - } - -})(this); \ No newline at end of file diff --git a/Core/automation/lib/javascript/core/utils.js b/Core/automation/lib/javascript/core/utils.js index a863624a..0fc3e984 100644 --- a/Core/automation/lib/javascript/core/utils.js +++ b/Core/automation/lib/javascript/core/utils.js @@ -11,9 +11,7 @@ var automationPath = OPENHAB_CONF+'/automation/'; var mainPath = automationPath + 'lib/javascript/core/'; //https://wiki.shibboleth.net/confluence/display/IDP30/ScriptedAttributeDefinition - - load(__DIR__+'/log.js'); - var logger = Logger(null); + var logger = Java.type("org.slf4j.LoggerFactory").getLogger("jsr223.javascript"); try { var RuleBuilder = Java.type("org.openhab.core.automation.util.RuleBuilder"); @@ -89,20 +87,20 @@ context.uuid = uuid; - context.logInfo = function (type , value) { - logger.info(Error(args(arguments))); + context.logInfo = function(type , value) { + logger.info(args(arguments)); }; - context.logWarn = function (type , value) { - logger.warn(Error(args(arguments))); + context.logWarn = function(type , value) { + logger.warn(args(arguments)); }; - context.logDebug = function (type , value) { - logger.debug(Error(args(arguments))); + context.logDebug = function(type , value) { + logger.debug(args(arguments)); }; - context.logError = function (type , value) { - logger.error(Error(args(arguments))); + context.logError = function(type , value) { + logger.error(args(arguments)); }; - context.logTrace = function (type , value) { - logger.trace(Error(args(arguments))); + context.logTrace = function(type , value) { + logger.trace(args(arguments)); }; @@ -112,8 +110,8 @@ context.console.debug = context.logDebug; context.console.error = context.logError; - context.console.log = function (value) { - logger.info(Error("console.log"), value); + context.console.log = function(value) { + logger.info("console.log", value); }; context.isUndefined = function(item) { From 067dac6a18d61c55e9699f33a012b683f222701b Mon Sep 17 00:00:00 2001 From: Martin Stangl Date: Tue, 22 Oct 2019 21:21:39 +0200 Subject: [PATCH 4/5] Fix: Wrong check for Error object Signed-off-by: Martin Stangl --- Core/automation/lib/javascript/core/log.js | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/Core/automation/lib/javascript/core/log.js b/Core/automation/lib/javascript/core/log.js index 98986d13..e8439471 100644 --- a/Core/automation/lib/javascript/core/log.js +++ b/Core/automation/lib/javascript/core/log.js @@ -114,11 +114,11 @@ }}, _getLogMessage: { value: function _getLogMessage (msg, prefix, levelString) { - if ((typeof msg) !== "object") { - msg = Error(msg); - msg = this._getCallerDetails(msg); - } else { + if (msg instanceof Error) { msg.caller = msg.stack.split('\n\tat ')[1].split(' (')[0] + } else { + msg = Error(msg); + msg = this._getCallerDetails(msg); } msg = this._legacyLoggerCorrection(msg); From 53cc3876bf8160c98526b30cda00c5b5f73b9611 Mon Sep 17 00:00:00 2001 From: Martin Stangl Date: Wed, 23 Oct 2019 22:17:46 +0200 Subject: [PATCH 5/5] Change to message format and logger name prefix Log message format changed for better readability. Private functions actually made private. Blank line added after end of code. Logger name prefix aligned with LogAction. Signed-off-by: Martin Stangl Signed-off-by: Martin Stangl --- Core/automation/lib/javascript/core/log.js | 285 +++++++++++---------- 1 file changed, 147 insertions(+), 138 deletions(-) diff --git a/Core/automation/lib/javascript/core/log.js b/Core/automation/lib/javascript/core/log.js index e8439471..1cafda7b 100644 --- a/Core/automation/lib/javascript/core/log.js +++ b/Core/automation/lib/javascript/core/log.js @@ -1,16 +1,16 @@ /** * Logging functions and variables - * + * * Copyright (c) 2019 Contributors to the openHAB Scripters project - * + * * @author Martin Stangl - initial contribution */ -'use strict'; +'use strict'; (function context (context) { - 'use strict'; - - load(__DIR__+'/actions.js'); + 'use strict'; + + load(__DIR__+'/actions.js'); context.NOTIFY_OFF = 0; context.NOTIFY_ERROR = 200; @@ -18,182 +18,191 @@ context.NOTIFY_INFO = 400; context.NOTIFY_DEBUG = 500; - context.Logger = function Logger (name, notificationLevel, config) { - if (name === undefined) { - name = Error().stack.split('\n')[2].split('/').slice(-2).join('.').split(':')[0]; - name = name.slice(-3) == ".js" ? name.slice(0,-3) : null; + context.Logger = function Logger (_name, _notificationLevel, _config) { + + var LOGGER_PREFIX = "org.eclipse.smarthome.model.script.jsr223.javascript"; + + var PATH_SEPARATOR = Java.type("java.lang.System").getenv("OPENHAB_CONF").split(Java.type("java.lang.System").getenv("OPENHAB_HOME")).pop()[0]; + var AUTOMATION_PATH = Java.type("java.lang.System").getenv("OPENHAB_CONF") + if (PATH_SEPARATOR === "\\") AUTOMATION_PATH = AUTOMATION_PATH.replace(/\\/g,'/'); + AUTOMATION_PATH = AUTOMATION_PATH + "/automation/"; + + if (_name === undefined) { + _name = Error().stack.split('\n')[2].split('/').slice(-2).join('.').split(':')[0]; + _name = _name.slice(-3) == ".js" ? _name.slice(0,-3) : null; } - var _logger = Java.type("org.slf4j.LoggerFactory").getLogger(name === null ? "jsr223.javascript" : "jsr223.javascript." + name.toString().toLowerCase()); - var _messageFormatter = Java.type("org.slf4j.helpers.MessageFormatter"); + var _logger = Java.type("org.slf4j.LoggerFactory").getLogger(_name === null ? LOGGER_PREFIX : LOGGER_PREFIX + "." + _name.toString().toLowerCase()); try { // Set default config for config params not provided. - if (config === undefined) config = {}; - if (config.ERROR === undefined) config.ERROR = {}; - if (config.WARN === undefined) config.WARN = {}; - if (config.INFO === undefined) config.INFO = {}; - if (config.DEBUG === undefined) config.DEBUG = {}; - if (config.ERROR.prefix === undefined) config.ERROR.prefix = "short"; - if (config.WARN.prefix === undefined) config.WARN.prefix = "none"; - if (config.INFO.prefix === undefined) config.INFO.prefix = "none"; - if (config.DEBUG.prefix === undefined) config.DEBUG.prefix = "short"; + if (_config === undefined) _config = {}; + if (_config.ERROR === undefined) _config.ERROR = {}; + if (_config.WARN === undefined) _config.WARN = {}; + if (_config.INFO === undefined) _config.INFO = {}; + if (_config.DEBUG === undefined) _config.DEBUG = {}; + if (_config.ERROR.prefix === undefined) _config.ERROR.prefix = "short"; + if (_config.WARN.prefix === undefined) _config.WARN.prefix = "none"; + if (_config.INFO.prefix === undefined) _config.INFO.prefix = "none"; + if (_config.DEBUG.prefix === undefined) _config.DEBUG.prefix = "short"; + + var _MessageFormatter = Java.type("org.slf4j.helpers.MessageFormatter"); + + var _getLogMessage = function _getLogMessage (msg, prefix, levelString) { + if (msg instanceof Error) { + msg.caller = msg.stack.split('\n\tat ')[1].split(' (')[0] + } else { + msg = Error(msg); + msg = _getCallerDetails(msg); + } + msg = _legacyLoggerCorrection(msg); + + if (prefix === undefined) prefix = "log"; + + if (prefix == "none") { + return msg.message; + } + + var level = ""; + var nameText = ""; + if (prefix != "log") { + level = "[" + levelString + "] "; + nameText = _name === null ? "" : _name; + } + + if (prefix == "level") { + return (level + msg.message); + } + + var callerText; + if (msg.caller.substr(0,1) == "<") { + callerText = ", in " + msg.caller; + } else { + callerText = ", function " + msg.caller; + } + + var message = msg.message == "" ? "" : msg.message + " "; + + if (prefix == "short") { + return (level + message + "\t\t[" + (nameText != "" ? nameText + ", " : "") + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + "]"); + } + return (level + message + "\t\t[" + (nameText != "" ? nameText + ": " : "") + "at source " + msg.fileName.split(AUTOMATION_PATH).pop() + ", line " + msg.lineNumber + callerText + "]"); + } + + var _getCallerDetails = function _getCallerDetails (msg) { + var matches = msg.stack.split('\n\tat ')[3].match(/(.+?) \((.+):(\d+?)\)/); + msg.caller = matches[1]; + msg.fileName = matches[2] + msg.lineNumber = matches[3] + return msg; + } + + var _sendNotification = function _sendNotification (message, icon, levelString, log) { + if (_config[levelString].recipients !== undefined) { + _config[levelString].recipients.forEach(function(mail){ + NotificationAction.sendNotification(mail, message, icon, levelString); + }) + if (_config[levelString].recipients.length > 0) { + log.trace(Error("Notification sent to " + _config[levelString].recipients.join(", ") + ". Message: \"" + message + "\"")); + } + } else { + NotificationAction.sendBroadcastNotification(message, icon, levelString); + log.trace(Error("Broadcast notification sent. Message: \"" + message + "\"")); + } + } + + var _legacyLoggerCorrection = function _legacyLoggerCorrection (msg) { + if (msg.fileName.search(/automation\/lib\/javascript\/core\/utils\.js$/) !== -1) { + switch (msg.caller) { + case "logError": + case "logWarn": + case "logInfo": + case "logDebug": + case "logTrace": + case "error": + case "warn": + case "info": + case "debug": + case "log": + var stackArray = msg.stack.split('\n\tat '); + stackArray.splice(3,1); + msg.stack = stackArray.join('\n\tat '); + msg = _getCallerDetails(msg); + } + } + return msg; + } return Object.create(Object.prototype, { - _notificationLevel: { value: (notificationLevel === undefined || notificationLevel === null) ? context.NOTIFY_OFF : notificationLevel }, - _config: { value: config }, - _name: { value: name }, + notificationLevel: { value: (_notificationLevel === undefined || _notificationLevel === null) ? context.NOTIFY_OFF : _notificationLevel }, + config: { value: _config }, + name: { value: _name }, error: { value: function error (msg) { try { - if (_logger.isErrorEnabled()) { - _logger.error(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); + if (_logger.isErrorEnabled()) { + _logger.error(_getLogMessage(msg), [].slice.call(arguments).slice(1)); } - if (this._notificationLevel >= context.NOTIFY_ERROR) { - this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.ERROR.prefix, "ERROR"), [].slice.call(arguments).slice(1)).getMessage(), "fire", "ERROR"); + if (this.notificationLevel >= context.NOTIFY_ERROR) { + _sendNotification(_MessageFormatter.arrayFormat(_getLogMessage(msg, this.config.ERROR.prefix, "ERROR"), [].slice.call(arguments).slice(1)).getMessage(), "fire", "ERROR", this); } } catch (err) { - _logger.error(this._getLogMessage(err)); + _logger.error(_getLogMessage(err)); } - }}, + }}, warn: { value: function warn (msg) { try { - if (_logger.isWarnEnabled()) { - _logger.warn(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); + if (_logger.isWarnEnabled()) { + _logger.warn(_getLogMessage(msg), [].slice.call(arguments).slice(1)); } - if (this._notificationLevel >= context.NOTIFY_WARN) { - this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.WARN.prefix, "WARN"), [].slice.call(arguments).slice(1)).getMessage(), "error", "WARN"); + if (this.notificationLevel >= context.NOTIFY_WARN) { + _sendNotification(_MessageFormatter.arrayFormat(_getLogMessage(msg, this.config.WARN.prefix, "WARN"), [].slice.call(arguments).slice(1)).getMessage(), "error", "WARN", this); } } catch (err) { - _logger.error(this._getLogMessage(err)); + _logger.error(_getLogMessage(err)); } }}, info: { value: function info (msg) { try { - if (_logger.isInfoEnabled()) { - _logger.info(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); + if (_logger.isInfoEnabled()) { + _logger.info(_getLogMessage(msg), [].slice.call(arguments).slice(1)); } - if (this._notificationLevel >= context.NOTIFY_INFO) { - this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.INFO.prefix, "INFO"), [].slice.call(arguments).slice(1)).getMessage(), "lightbulb", "INFO"); + if (this.notificationLevel >= context.NOTIFY_INFO) { + _sendNotification(_MessageFormatter.arrayFormat(_getLogMessage(msg, this.config.INFO.prefix, "INFO"), [].slice.call(arguments).slice(1)).getMessage(), "lightbulb", "INFO", this); } } catch (err) { - _logger.error(this._getLogMessage(err)); + _logger.error(_getLogMessage(err)); } }}, debug: { value: function debug (msg) { try { - if (_logger.isDebugEnabled()) { - _logger.debug(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); + if (_logger.isDebugEnabled()) { + _logger.debug(_getLogMessage(msg), [].slice.call(arguments).slice(1)); } - if (this._notificationLevel >= context.NOTIFY_DEBUG) { - this._sendNotification(_messageFormatter.arrayFormat(this._getLogMessage(msg, this._config.DEBUG.prefix, "DEBUG"), [].slice.call(arguments).slice(1)).getMessage(), "text", "DEBUG"); + if (this.notificationLevel >= context.NOTIFY_DEBUG) { + _sendNotification(_MessageFormatter.arrayFormat(_getLogMessage(msg, this.config.DEBUG.prefix, "DEBUG"), [].slice.call(arguments).slice(1)).getMessage(), "text", "DEBUG", this); } } catch (err) { - _logger.error(this._getLogMessage(err)); + _logger.error(_getLogMessage(err)); } }}, trace: { value: function trace (msg) { - try { - if (_logger.isTraceEnabled()) { - _logger.trace(this._getLogMessage(msg), [].slice.call(arguments).slice(1)); + try { + if (_logger.isTraceEnabled()) { + _logger.trace(_getLogMessage(msg), [].slice.call(arguments).slice(1)); } - } catch (err) { - _logger.error(this._getLogMessage(err)); - } - }}, - - _getCallerDetails: { value: function _getCallerDetails (msg) { - var matches = msg.stack.split('\n\tat ')[3].match(/(.+?) \((.+):(\d+?)\)/); - msg.caller = matches[1]; - msg.fileName = matches[2] - msg.lineNumber = matches[3] - return msg; - }}, - - _getLogMessage: { value: function _getLogMessage (msg, prefix, levelString) { - if (msg instanceof Error) { - msg.caller = msg.stack.split('\n\tat ')[1].split(' (')[0] - } else { - msg = Error(msg); - msg = this._getCallerDetails(msg); - } - msg = this._legacyLoggerCorrection(msg); - - if (prefix === undefined) prefix = "log"; - - if (prefix == "none") { - return msg.message; - } - - var level = ""; - var name = ""; - if (prefix != "log") { - level = "[" + levelString + "] "; - name = this._name === null ? "" : this._name; - } - - if (prefix == "level") { - return (level + msg); - } - - var callerText; - if (msg.caller.substr(0,1) == "<") { - callerText = ", in " + msg.caller; - } else { - callerText = ", function " + msg.caller; - } - - var message = msg.message == "" ? "" : "] " + msg.message; - - if (prefix == "short") { - return (level + "[" + (name != "" ? name + ", " : "") + msg.fileName.split('/').pop() + ":" + msg.lineNumber + callerText + message); - } - return (level + "[" + (name != "" ? name + ": " : "") + "source " + msg.fileName + ", line " + msg.lineNumber + callerText + message); - }}, - - _legacyLoggerCorrection: { value: function _legacyLoggerCorrection (msg) { - if (msg.fileName.search(/automation\/lib\/javascript\/core\/utils\.js$/) !== -1) { - switch (msg.caller) { - case "logError": - case "logWarn": - case "logInfo": - case "logDebug": - case "logTrace": - case "error": - case "warn": - case "info": - case "debug": - case "log": - var stackArray = msg.stack.split('\n\tat '); - stackArray.splice(3,1); - msg.stack = stackArray.join('\n\tat '); - msg = this._getCallerDetails(msg); - } + } catch (err) { + _logger.error(_getLogMessage(err)); } - return msg; - }}, - - _sendNotification: { value: function _sendNotification (message, icon, levelString) { - if (this._config[levelString].recipients !== undefined) { - this._config[levelString].recipients.forEach(function(mail){ - NotificationAction.sendNotification(mail, message, icon, levelString); - }) - if (this._config[levelString].recipients.length > 0) { - this.trace(Error("Notification sent to " + this._config[levelString].recipients.join(", ") + ". Message: \"" + message + "\"")); - } - } else { - NotificationAction.sendBroadcastNotification(message, icon, levelString); - this.trace(Error("Broadcast notification sent. Message: \"" + message + "\"")); - } }} }) } catch (err) { - _logger.error(err.fileName + ", line " + err.lineNumber + ": " + err.message); + _logger.error(err.message + " [source " + err.fileName + ", line " + err.lineNumber + "]"); } - } + } -})(this); \ No newline at end of file +})(this);