1.3.2 release branch - DO NOT MERGE :P

gpii/node_modules/eventLog/src/eventLog.js

@@ -22,7 +22,6 @@
 
 var fluid = require("infusion");
 var fs = require("fs"),
-    path = require("path"),
     moment = require("moment"),
     net = require("net");
 
@@ -39,9 +38,6 @@ fluid.defaults("gpii.eventLog", {
         },
         settingsDir: {
             type: "gpii.settingsDir"
-        },
-        metrics: {
-            type: "gpii.metrics"
         }
     },
     invokers: {
@@ -51,23 +47,41 @@ fluid.defaults("gpii.eventLog", {
         },
         logError: "gpii.eventLog.logError",
         getGpiiSettingsDir: "{settingsDir}.getGpiiSettingsDir",
-        getLogFile: "gpii.eventLog.getLogFile",
-        getVersion: "gpii.eventLog.getVersion"
+        getVersion: "gpii.eventLog.getVersion",
+        setState: {
+            funcName: "gpii.eventLog.setState",
+            args: ["{eventLog}", "{arguments}.0", "{arguments}.1"] // name, value
+        }
     },
     members: {
-        // The installation ID
-        installationID: "@expand:{that}.installID.getInstallID()",
-        version: "@expand:{that}.getVersion()",
         sequence: 0,
         // Buffered log lines while there's not log server connection
         logBuffer: [],
+        logLevel: fluid.logLevel.INFO,
         // Maximum number of lines to buffer.
-        maxBufferlength: 0xfff
+        maxBufferlength: 0xfff,
+        // A TCP socket to send the log entries to (filebeat service).
+        logServer: {
+            host: null,
+            port: null
+        },
+        // A file to write the log entries to.
+        logPath: null,
+        // Data to include in every log entry.
+        eventData: {
+            // The installation ID
+            installID: "@expand:{that}.installID.getInstallID()",
+            version: "@expand:{that}.getVersion()",
+            sessionID: undefined,
+            gpiiKey: undefined
+        },
+        // The start times for events which require durations to be recorded.
+        eventTimes: {}
     },
     listeners: {
         "onCreate.logFile": {
-            func: "gpii.eventLog.getLogFile",
-            args: ["{that}"]
+            func: "gpii.eventLog.initLogDestination",
+            args: ["{that}", "{that}.options.logDestination"]
         },
         "onCreate.log": {
             func: "gpii.eventLog.logStartStop",
@@ -78,10 +92,22 @@ fluid.defaults("gpii.eventLog", {
             args: ["{that}", "stop"]
         }
     },
-
-    logDestination: "tcp://127.0.0.1:51481"
+    // File path, or tcp://host:port
+    logDestination: null
 });
 
+/**
+ * A log event
+ * @typedef {Object} LogEvent
+ * @property {String} module The area of GPII the event is from.
+ * @property {String} event The name of the event.
+ * @property {String} data [optional] Extra information about the event.
+ * @property {Object} level The severity of the event (from fluid.logLevelsSpec, default: fluid.INFO).
+ * @property {String} version The eventLog module version. (automatically added)
+ * @property {String} timestamp Current time of the event. (automatically added)
+ * @property {String} sequence Ordered unique identifier to the event. (automatically added)
+ */
+
 /**
  * Returns the actual date and time, as a string, in ISO 8601 format with the localtime + offset from UTC.
  * eg: '2018-07-13T13:03:03.863+01:00'
@@ -125,7 +151,7 @@ gpii.eventLog.logStartStop = function (that, state) {
  * @param {String} event - Name of the event.
  * @param {Any} [data] - [optional] Event specific data.
  * @param {Object} level -[optional] Level of the log, see fluid.logLevelsSpec [FATAL,FAIL,WARN,IMPORTANT,INFO,TRACE].
- * @return {Object} The log object.
+ * @return {LogEvent} The log object.
  */
 gpii.eventLog.createLogObject = function (moduleName, event, data, level) {
     var eventObject = {
@@ -184,8 +210,11 @@ gpii.eventLog.logError = function (that, moduleName, errType, err, level) {
     if (err instanceof Error) {
         // Error doesn't serialise
         data.error = {};
-        fluid.each(Object.getOwnPropertyNames(err), function (a) {
-            data.error[a] = err[a];
+        fluid.each(Object.getOwnPropertyNames(err), function (source) {
+            // Ensure the first character of the field is lowercase -  "Message" vs "message" was causing a duplicate
+            // field during the analysis.
+            var dest = source.charAt(0).toLowerCase() + source.slice(1);
+            data.error[dest] = err[source];
         });
     } else if (fluid.isPlainObject(err, true)) {
         data.error = Object.assign({}, err);
@@ -228,73 +257,86 @@ gpii.eventLog.gotError = function (err, errType) {
 fluid.onUncaughtException.addListener(gpii.eventLog.gotError, "gpii-eventLog");
 
 /**
- * Gets the path of the new log file for this instance of gpii.
- * It can use one of the following environment variables to override the configured:
- *  GPII_EVENT_LOG: The path to the log file (a file, or tcp://<host>:<port>).
- *  GPII_EVENT_LOG_DIRECTORY: A directory where per-instance logs are kept
+ * Parses the log path (which can be overridden by the GPII_EVENT_LOG environment variable), and sets either the
+ * logServer or logPath member.
  *
  * @param {Component} that - The gpii.eventLog instance.
- * @return {String} The path to the new log file.
+ * @param {String} logPath - The path to the log file (a file, or a tcp socket in the format of `tcp://<host>:<port>`).
  */
-gpii.eventLog.getLogFile = function (that) {
-    var logPath;
-    if (!process.env.GPII_EVENT_LOG_DIRECTORY) {
-        logPath = process.env.GPII_EVENT_LOG || that.logFilePath || that.options.logDestination;
-    }
+gpii.eventLog.initLogDestination = function (that, logPath) {
+    logPath = process.env.GPII_EVENT_LOG || logPath;
 
-    if (logPath) {
-        if (logPath.startsWith("tcp:")) {
-            var m = /tcp:\/*([^:]+):([0-9]+)/.exec(logPath);
-            if (m) {
-                that.logHost = m[1];
-                that.logPort = m[2];
-                that.logFilePath = null;
-            }
-        } else {
-            that.logHost = null;
-            that.logFilePath = logPath;
-        }
+    var match = logPath && /tcp:\/*([^:]+):([0-9]+)/.exec(logPath);
+    if (match) {
+        that.logServer.host = match[1];
+        that.logServer.port = match[2];
     } else {
-        that.logHost = null;
-        var startupTime = Date.now();
-        var gpiiSettingsDir = process.env.GPII_EVENT_LOG_DIRECTORY || that.getGpiiSettingsDir();
-        that.logFilePath = path.join(gpiiSettingsDir, "gpii-" + gpii.journal.formatTimestamp(startupTime) + ".log");
+        that.logPath = logPath;
     }
 
-    var dest = that.logHost ? ("tcp://" + that.logHost + ":" + that.logPort) : that.logFilePath;
+    var dest = that.logServer.host ? ("tcp://" + that.logServer.host + ":" + that.logServer.port) : that.logPath;
     fluid.log(fluid.logLevel.IMPORTANT, "Writing event log to " + dest);
-
-    return that.logFilePath;
 };
 
 /**
  * Writes an event to the log file.
  *
  * @param {Component} that - The gpii.eventLog instance.
  * @param {Object} level - Level of the log, see fluid.logLevelsSpec [FATAL,FAIL,WARN,IMPORTANT,INFO,TRACE].
- * @param {Object} event - The object. This will be modified to what has been sent to the log, adding the installID and
+ * @param {LogEvent} event - The object. This will be modified to what has been sent to the log, adding the installID and
  * timestamp fields.
  */
 gpii.eventLog.writeLog = function (that, level, event) {
-    var intLevel = gpii.eventLog.checkLevel(level);
-    event.level = intLevel.value;
+    var eventLevel = gpii.eventLog.checkLevel(level);
+    event.level = eventLevel.value;
 
-    // Log to console before the installation ID and timestamp are added (no one wants to see it).
-    fluid.log(fluid.logLevel.TRACE, event);
+    gpii.eventLog.recordDuration(that, event);
 
-    event.installID = that.installationID;
+    Object.assign(event, that.eventData);
     event.timestamp = gpii.eventLog.getTimestamp();
-    event.version = that.version;
     event.sequence = that.sequence++;
 
-    var logLine = JSON.stringify(event) + "\n";
+    if (eventLevel.priority <= that.logLevel.priority) {
+        var logLine = JSON.stringify(event) + "\n";
+
+        if (that.logServer.host && that.logServer.port) {
+            gpii.eventLog.writeLogTcp(that, logLine);
+        }
 
-    if (that.logHost && that.logPort) {
-        gpii.eventLog.writeLogTcp(that, logLine);
+        if (that.logPath) {
+            fs.appendFileSync(that.logPath, logLine);
+        }
     }
+};
 
-    if (that.logFilePath) {
-        fs.appendFileSync(that.logFilePath, logLine);
+/**
+ * Handles the timing of a pair of duration events.
+ *
+ * Some events can be paired into having a duration. For example, tooltip-shown and tooltip-hidden. The timestamp for
+ * the start event is recorded, so when the end event is seen the duration is calculated and added to the event data.
+ *
+ * @param {Component} that The gpii.eventLog instance.
+ * @param {LogEvent} event The event.
+ */
+gpii.eventLog.recordDuration = function (that, event) {
+    var endEvent = that.options.durationEvents[event.event];
+    if (endEvent) {
+        // This is the start of a pair of duration events.
+        if (!that.eventTimes[endEvent]) {
+            that.eventTimes[endEvent] = [];
+        }
+        that.eventTimes[endEvent].push(process.hrtime());
+    } else {
+        var startTimes = that.eventTimes[event.event];
+        var startTime = startTimes && startTimes.pop();
+        if (startTime) {
+            // This is the ending of a pair of duration events.
+            if (!event.data) {
+                event.data = {};
+            }
+            var memberName = event.data.hasOwnProperty("duration") ? "duration_auto" : "duration";
+            event.data[memberName] = process.hrtime(startTime)[0];
+        }
     }
 };
 
@@ -334,7 +376,7 @@ gpii.eventLog.connectLog = function (that) {
 
     // Connect to the server.
     that.logSocket = new net.Socket();
-    that.logSocket.connect(that.logPort, that.logHost, function () {
+    that.logSocket.connect(that.logServer.port, that.logServer.host, function () {
         gpii.eventLog.connectLog.lastError = null;
         fluid.log("Connected to log server");
         // Send the initial data.
@@ -368,12 +410,29 @@ gpii.eventLog.connectLog = function (that) {
  * Sets INFO as default loglevel
  *
  * @param {Object} level - Level to check, can be a string that represents the value or a property of fluid.logLevel.
- * @return {Integer} A valid fluid.logLevel, with INFO as default.
+ * @return {Object} A valid fluid.logLevel, with INFO as default.
  */
 gpii.eventLog.checkLevel = function (level) {
+    var togo;
     if (typeof level === "string" && level in fluid.logLevelsSpec) {
-        return fluid.logLevel[level];
+        togo = fluid.logLevel[level];
+    } else {
+        togo = fluid.isLogLevel(level) && level;
+    }
+    return togo || fluid.logLevel.INFO;
+};
+
+/**
+ * Specifies a field which gets logged with every subsequent event.
+ *
+ * @param {Component} that The gpii.eventLog instance.
+ * @param {String} name The name of the field.
+ * @param {Object} value The field value. undefined or null will remove the field.
+ */
+gpii.eventLog.setState = function (that, name, value) {
+    if (value === undefined || value === null) {
+        delete that.eventData[name];
     } else {
-        return fluid.isLogLevel(level) ? level : fluid.logLevel.INFO;
+        that.eventData[name] = value;
     }
 };