Skip to content

Initial contribution core/log.js #268

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 7 commits into
base: master
Choose a base branch
from
Open

Initial contribution core/log.js #268

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
995c762
initial contribution core/log.js
Martin-Stangl Oct 18, 2019
f25bf61
log string added, fixed parameterization for notifications, legacy co…
Martin-Stangl Oct 19, 2019
91a89a0
Revert master back to upstream state.
Martin-Stangl Oct 19, 2019
067dac6
Fix: Wrong check for Error object
Martin-Stangl Oct 22, 2019
45ea7e4
Merge branch 'master' of https://github.com/openhab-scripters/openhab…
Martin-Stangl Oct 22, 2019
7d5ea41
Merge branch 'master' into feature-logger
Martin-Stangl Oct 22, 2019
53cc387
Change to message format and logger name prefix
Martin-Stangl Oct 23, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
208 changes: 208 additions & 0 deletions Core/automation/lib/javascript/core/log.js
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,208 @@
/**
* 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) {

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 ? 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";

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+?)\)/);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same comment as below - this stack parsing is specific to Nashorn; /\s+at\s+/ should work for Nashorn + others.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, same comment as below.

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 ');
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use /\s+at\s+/ rather than '\n\tat '?
The current version is very specific, and (for example) fails on GraalJS which uses spaces rather than tabs.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should be able to adjust it to also work with GraalJS.
But we have to be very specific, as the stack also contains the message text, which can be whatever the user wants it to be, including multi-line.
Therefore I think your suggestions is way too unspecific, as it would grab occurrence of the word "at".
Worst case, I might need to identify the engine we are running on and define a regex for each specifically.

Copy link

@jpg0 jpg0 Nov 1, 2019 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, good point. I just dropped that in to keep it working in my env. I would expect that ensuring it's the start of the line /^\s+at\s+ would be better, or even just fixing it to tab OR 4x space /^(\t| )at\s+ (<- github butchers the 4 spaces in this, but you know what I mean). Personally I wouldn't try to detect the engine.

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 },

error: { value: function error (msg) {
try {
if (_logger.isErrorEnabled()) {
_logger.error(_getLogMessage(msg), [].slice.call(arguments).slice(1));
}
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(_getLogMessage(err));
}
}},

warn: { value: function warn (msg) {
try {
if (_logger.isWarnEnabled()) {
_logger.warn(_getLogMessage(msg), [].slice.call(arguments).slice(1));
}
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(_getLogMessage(err));
}
}},

info: { value: function info (msg) {
try {
if (_logger.isInfoEnabled()) {
_logger.info(_getLogMessage(msg), [].slice.call(arguments).slice(1));
}
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(_getLogMessage(err));
}
}},

debug: { value: function debug (msg) {
try {
if (_logger.isDebugEnabled()) {
_logger.debug(_getLogMessage(msg), [].slice.call(arguments).slice(1));
}
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(_getLogMessage(err));
}
}},

trace: { value: function trace (msg) {
try {
if (_logger.isTraceEnabled()) {
_logger.trace(_getLogMessage(msg), [].slice.call(arguments).slice(1));
}
} catch (err) {
_logger.error(_getLogMessage(err));
}
}}

})
} catch (err) {
_logger.error(err.message + " [source " + err.fileName + ", line " + err.lineNumber + "]");
}
}

})(this);
25 changes: 18 additions & 7 deletions Core/automation/lib/javascript/core/utils.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,10 @@
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);
var loggerConsole = Logger("console");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All of the logging functionality should be stripped out of utils.js. The utils.js library will end up being used to hold helper functions for use in scripts and libs. This is a breaking change, but these should be expected... https://github.com/openhab-scripters/openhab-helper-libraries/blob/master/README.md#-under-construction-.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK. I will the go ahead and remove this from utils.js.
But this means I have to rework all log calls all exiting core libraries.

So I first want to resolve, if we will emulate console.log (most likely yes).

Also it might be better that @jpg0 gets his CommonJS stuff done and merged into the master, before I start also changing all libraries.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But this means I have to rework all log calls all exiting core libraries.

I'm missing something... I did not think there was much effort to pull logging out of utils.js. But yes... if the core libs need reworked for logging, then it should wait for CommonJS, if that is the direction we're going... haven't dug into that one yet!

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, I could just take the log methods as they are in utils.js and move them to log.js. But if we completely forego backwards compatibility and get rid of logError, logWarn, ..., I do not see much value in that. Better to leave them in utils.js, until we actually get rid of them and not pollute the new library with it.
And logError, logWarn, ...are used by the core libraries, So this needs to be changed to get rid of these methods.


try {
var RuleBuilder = Java.type("org.openhab.core.automation.util.RuleBuilder");
Expand Down Expand Up @@ -105,13 +108,21 @@


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("console.log", value);
context.console.log = function (value) {
loggerConsole.info(value);
};

context.isUndefined = function(item) {
Expand Down