add logging and unit tests (#117)

* add logging and unit tests

* fix logging msg spell for notification

.babelrc

@@ -1,3 +0,0 @@
-{
-  "presets": ["es2015"]
-}

js/activityDetection/activityDetection.js

@@ -2,6 +2,8 @@
 
 const systemIdleTime = require('@paulcbetts/system-idle-time');
 const throttle = require('../utils/throttle');
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
 
 let maxIdleTime;
 let activityWindow;
@@ -75,6 +77,7 @@ function sendActivity() {
  */
 function send(data) {
     if (activityWindow && data) {
+        log.send(logLevels.INFO, 'activity occurred at time= ' + new Date().toUTCString());
         activityWindow.send('activity', {
             systemIdleTime: data.systemIdleTime
         });

js/config.js

@@ -8,6 +8,8 @@ const isDevEnv = require('./utils/misc.js').isDevEnv;
 const isMac = require('./utils/misc.js').isMac;
 const getRegistry = require('./utils/getRegistry.js');
 const configFileName = 'Symphony.config';
+const log = require('./log.js');
+const logLevels = require('./enums/logLevels.js');
 
 /**
  * Tries to read given field from user config file, if field doesn't exist
@@ -156,6 +158,7 @@ function saveUserConfig(fieldName, newValue, oldConfig) {
 
         fs.writeFile(configPath, jsonNewConfig, 'utf8', (err) => {
             if (err) {
+                log.send(logLevels.ERROR, 'error saving to user config file: ' + configPath + ',error:' + err);
                 reject(err);
             } else {
                 resolve(newConfig);

js/dialogs/showCertError.js

@@ -2,6 +2,9 @@
 
 const electron = require('electron');
 
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
+
 let ignoreAllCertErrors = false;
 
 /**
@@ -21,6 +24,8 @@ electron.app.on('certificate-error', function(event, webContents, url, error,
         return;
     }
 
+    log.send(logLevels.WARNING, 'Certificate error: ' + error + ' for url: ' + url);
+
     const browserWin = electron.BrowserWindow.fromWebContents(webContents);
     const buttonId = electron.dialog.showMessageBox(browserWin, {
         type: 'warning',

js/dialogs/showLoadError.js

@@ -2,6 +2,9 @@
 
 const electron = require('electron');
 
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
+
 /**
  * Show dialog pinned to given window when loading error occurs
  * @param  {BrowserWindow} win       Window to host dialog
@@ -34,6 +37,9 @@ function showLoadFailure(win, url, errorDesc, errorCode, retryCallback) {
         message: msg
     }, response);
 
+    log.send(logLevels.WARNING, 'Load failure msg: ' + errorDesc +
+    ' errorCode: ' + errorCode + ' for url:' + url);
+
     // async handle of user input
     function response(buttonId) {
         // retry if hitting butotn index 0 (i.e., reload)

js/log.js

@@ -1,28 +1,87 @@
 'use strict';
 
-let logWindow;
+const getCmdLineArg = require('./utils/getCmdLineArg.js')
 
-/**
- * Send log messages from main process to logger hosted by
- * renderer process. Allows main process to use logger
- * provided by JS.
- * @param  {enum} level      enum from ./enums/LogLevel.js
- * @param  {string} details  msg to be logged
- */
-function send(level, details) {
-    if (logWindow && level && details) {
-        logWindow.send('log', {
+const MAX_LOG_QUEUE_LENGTH = 100;
+
+class Logger {
+    constructor() {
+        // browser window that has registered a logger
+        this.logWindow = null;
+
+        // holds log messages received before logger has been registered.
+        this.logQueue = [];
+    }
+
+    /**
+     * Send log messages from main process to logger hosted by
+     * renderer process. Allows main process to use logger
+     * provided by JS.
+     * @param  {enum} level      enum from ./enums/LogLevel.js
+     * @param  {string} details  msg to be logged
+     */
+    send(level, details) {
+        if (!level || !details) {
+            return;
+        }
+
+        let logMsg = {
             level: level,
-            details: details
-        });
+            details: details,
+            startTime: Date.now()
+        };
+
+        if (this.logWindow) {
+            this.logWindow.send('log', {
+                msgs: [ logMsg ]
+            });
+        } else {
+            // store log msgs for later when (if) we get logger registered
+            this.logQueue.push(logMsg);
+            // don't store more than 100 msgs. keep most recent log msgs.
+            if (this.logQueue.length > MAX_LOG_QUEUE_LENGTH) {
+                this.logQueue.shift();
+            }
+        }
+    }
+
+    setLogWindow(win) {
+        this.logWindow = win;
+
+        if (this.logWindow) {
+            var logMsg = {};
+
+            if (Array.isArray(this.logQueue)) {
+                logMsg.msgs = this.logQueue;
+            }
+
+            // configure desired log level and send pending log msgs
+            let logLevel = getCmdLineArg(process.argv, '--logLevel=');
+            if (logLevel) {
+                let level = logLevel.split('=')[1];
+                if (level) {
+                    logMsg.logLevel = level;
+                }
+            }
+
+            if (getCmdLineArg(process.argv, '--enableConsoleLogging')) {
+                logMsg.showInConsole = true;
+            }
+
+            if (Object.keys(logMsg).length) {
+                this.logWindow.send('log', logMsg);
+            }
+
+            this.logQueue = [];
+        }
     }
 }
 
-function setLogWindow(win) {
-    logWindow = win;
-}
+var loggerInstance = new Logger();
 
+// Logger class is only exposed for testing purposes.
 module.exports = {
-    send: send,
-    setLogWindow: setLogWindow
-};
+    Logger: Logger,
+    send: loggerInstance.send.bind(loggerInstance),
+    setLogWindow: loggerInstance.setLogWindow.bind(loggerInstance)
+}

js/main.js

@@ -9,6 +9,7 @@ const urlParser = require('url');
 const { getConfigField } = require('./config.js');
 const { isMac, isDevEnv } = require('./utils/misc.js');
 const protocolHandler = require('./protocolHandler');
+const getCmdLineArg = require('./utils/getCmdLineArg.js')
 
 // used to check if a url was opened when the app was already open
 let isAppAlreadyOpen = false;
@@ -86,27 +87,18 @@ function setupThenOpenMainWindow() {
 
     isAppAlreadyOpen = true;
 
-    let installMode = false;
-
     // allows installer to launch app and set auto startup mode then
     // immediately quit.
-    process.argv.some((val) => {
-
-        let flag = '--install';
-        if (val === flag && !isMac) {
-            installMode = true;
-            getConfigField('launchOnStartup')
-            .then(setStartup)
-            .then(app.quit)
-            .catch(app.quit);
-        }
-
-        return false;
-    });
-
-    if (installMode === false) {
-        getUrlAndCreateMainWindow();
+    let hasInstallFlag = getCmdLineArg(process.argv, '--install', true);
+    if (!isMac && hasInstallFlag) {
+        getConfigField('launchOnStartup')
+        .then(setStartup)
+        .then(app.quit)
+        .catch(app.quit);
+        return;
     }
+
+    getUrlAndCreateMainWindow();
 }
 
 function setStartup(lStartup){
@@ -127,14 +119,9 @@ function setStartup(lStartup){
 function getUrlAndCreateMainWindow() {
     // for dev env allow passing url argument
     if (isDevEnv) {
-        let url;
-        process.argv.forEach((val) => {
-            if (val.startsWith('--url=')) {
-                url = val.substr(6);
-            }
-        });
+        let url = getCmdLineArg(process.argv, '--url=')
         if (url) {
-            windowMgr.createMainWindow(url);
+            windowMgr.createMainWindow(url.substr(6));
             return;
         }
     }
@@ -158,6 +145,7 @@ function createWin(urlFromConfig) {
         slahes: true,
         pathname: parsedUrl.href
     });
+
     windowMgr.createMainWindow(url);
 }
 
@@ -174,16 +162,7 @@ function processProtocolAction(argv) {
         return;
     }
 
-    let protocolUri;
-
-    for (let i = 0; i < argv.length; i++) {
-
-        if (argv[i].startsWith("symphony://")) {
-            protocolUri = argv[i];
-            break;
-        }
-
-    }
+    let protocolUri = getCmdLineArg(argv, 'symphony://');
 
     if (protocolUri) {
 

js/notify/electron-notify-preload.js

@@ -53,7 +53,7 @@ function setContents(event, notificationObj) {
                 audio.play()
             }
         } catch (e) {
-            log('electron-notify: ERROR could not find sound file: ' + notificationObj.sound.replace('file://', ''), e, e.stack);
+            log.send('electron-notify: ERROR could not find sound file: ' + notificationObj.sound.replace('file://', ''), e, e.stack);
         }
     }
 

js/notify/electron-notify.js

@@ -158,7 +158,7 @@ function getTemplatePath() {
     try {
         fs.statSync(templatePath).isFile();
     } catch (err) {
-        log('electron-notify: Could not find template ("' + templatePath + '").');
+        log.send('electron-notify: Could not find template ("' + templatePath + '").');
     }
     config.templatePath = 'file://' + templatePath;
     return config.templatePath;
@@ -166,7 +166,7 @@ function getTemplatePath() {
 
 function calcDimensions() {
     const vertSpaceBetweenNotf = 8;
-    
+
     // Calc totalHeight & totalWidth
     config.totalHeight = config.height + vertSpaceBetweenNotf;
     config.totalWidth = config.width
@@ -254,7 +254,7 @@ function notify(notification) {
         })
         return notf.id
     }
-    log('electron-notify: ERROR notify() only accepts a single object with notification parameters.')
+    log.send('electron-notify: ERROR notify() only accepts a single object with notification parameters.')
     return null;
 }
 

js/notify/notifyImpl.js

@@ -2,7 +2,8 @@
 
 const EventEmitter = require('events');
 const { notify } = require('./electron-notify.js');
-
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
 /**
  * implementation for notifications interface,
  * wrapper around electron-notify.
@@ -27,6 +28,8 @@ class Notify {
      * }
      */
     constructor(title, options) {
+        log.send(logLevels.INFO, 'creating notification, text=' + options.body);
+
         let emitter = new EventEmitter();
         this.emitter = Queue(emitter);
 
@@ -44,10 +47,13 @@ class Notify {
             onErrorFunc: onError.bind(this)
         });
 
+        log.send(logLevels.INFO, 'created notification, id=' + this._id + ', text=' + options.body);
+
         this._data = options.data || null;
 
         function onShow(arg) {
             if (arg.id === this._id) {
+                log.send(logLevels.INFO, 'showing notification, id=' + this._id);
                 this.emitter.queue('show', {
                     target: this
                 });
@@ -57,6 +63,7 @@ class Notify {
 
         function onClick(arg) {
             if (arg.id === this._id) {
+                log.send(logLevels.INFO, 'clicking notification, id=' + this._id);
                 this.emitter.queue('click', {
                     target: this
                 });
@@ -65,6 +72,7 @@ class Notify {
 
         function onClose(arg) {
             if (arg.id === this._id || arg.event === 'close-all') {
+                log.send(logLevels.INFO, 'closing notification, id=' + this._id);
                 this.emitter.queue('close', {
                     target: this
                 });
@@ -76,6 +84,8 @@ class Notify {
             if (arg.id === this._id) {
                 // don't raise error event if handler doesn't exist, node
                 // will throw an exception
+                log.send(logLevels.ERROR, 'error for notification, id=' + this._id +
+                    ' error=' + (arg && arg.error));
                 if (this.emitter.eventNames().includes('error')) {
                     this.emitter.queue('error', arg.error || 'notification error');
                 }

js/preload/preloadMain.js

@@ -210,7 +210,6 @@ function createAPI() {
          * for interface: see documentation in desktopCapturer/getSources.js
          */
         getMediaSources: getMediaSources
-
     };
 
     // add support for both ssf and SYM_API name-space.
@@ -220,8 +219,8 @@ function createAPI() {
 
     // listen for log message from main process
     local.ipcRenderer.on('log', (event, arg) => {
-        if (local.logger && arg && arg.level && arg.details) {
-            local.logger(arg.level, arg.details);
+        if (arg && local.logger) {
+            local.logger(arg.msgs || [], arg.logLevel, arg.showInConsole);
         }
     });
 
@@ -299,7 +298,6 @@ function createAPI() {
      * @type {String} arg - the protocol url
      */
     local.ipcRenderer.on('protocol-action', (event, arg) => {
-
         if (local.processProtocolAction && arg) {
             local.processProtocolAction(arg);
         }

js/protocolHandler/index.js

@@ -1,5 +1,8 @@
 'use strict';
 
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
+
 let protocolWindow;
 let protocolUrl;
 
@@ -8,7 +11,8 @@ let protocolUrl;
  * @param {String} uri - the uri opened in the format 'symphony://...'
  */
 function processProtocolAction(uri) {
-    if (protocolWindow && uri && uri.startsWith("symphony://")) {
+    log.send(logLevels.INFO, 'protocol action, uri=' + uri);
+    if (protocolWindow && uri && uri.startsWith('symphony://')) {
         protocolWindow.send('protocol-action', uri);
     }
 }

js/screenSnippet/ScreenSnippet.js

@@ -8,6 +8,8 @@ const os = require('os');
 const path = require('path');
 
 const { isMac, isDevEnv } = require('../utils/misc.js');
+const log = require('../log.js');
+const logLevels = require('../enums/logLevels.js');
 
 // static ref to child process, only allow one screen snippet at time, so
 // hold ref to prev, so can kill before starting next snippet.
@@ -34,6 +36,8 @@ class ScreenSnippet {
         return new Promise((resolve, reject) => {
             let captureUtil, captureUtilArgs;
 
+            log.send(logLevels.INFO, 'starting screen capture');
+
             let tmpFilename = 'symphonyImage-' + Date.now() + '.jpg';
             let tmpDir = os.tmpdir();
 
@@ -60,6 +64,8 @@ class ScreenSnippet {
                 captureUtilArgs = [ outputFileName ];
             }
 
+            log.send(logLevels.INFO, 'starting screen capture util: ' + captureUtil + ' with args=' + captureUtilArgs);
+
             // only allow one screen capture at a time.
             if (child) {
                 child.kill();

js/utils/getCmdLineArg.js

@@ -0,0 +1,25 @@
+'use strict';
+
+/**
+ * Search given argv for argName using exact match or starts with.
+ * @param  {Array} argv       Array of strings
+ * @param  {String} argName   Arg name to search for.
+ * @param  {bool} exactMatch  If true then look for exact match otherwise
+ * try finding arg that starts with argName.
+ * @return {String}           If found, returns the arg, otherwise null.
+ */
+function getCmdLineArg(argv, argName, exactMatch) {
+    if (!Array.isArray(argv)) {
+        return null;
+    }
+
+    for (let i = 0, len = argv.length; i < len; i++) {
+        if ((exactMatch && argv[i] === argName) ||
+            (!exactMatch && argv[i].startsWith(argName))) {
+            return argv[i];
+        }
+    }
+
+    return null;
+}
+module.exports = getCmdLineArg

js/windowMgr.js

@@ -66,6 +66,8 @@ function doCreateMainWindow(initialUrl, initialBounds) {
     let url = initialUrl;
     let key = getGuid();
 
+    log.send(logLevels.INFO, 'creating main window url: ' + url);
+
     let newWinOpts = {
         title: 'Symphony',
         show: true,
@@ -132,7 +134,7 @@ function doCreateMainWindow(initialUrl, initialBounds) {
         } else {
             // removes all existing notifications when main window reloads
             notify.reset();
-            log.send(logLevels.INFO, 'main window loaded url: ' + url);
+            log.send(logLevels.INFO, 'loaded main window url: ' + url);
 
         }
     });
@@ -200,6 +202,8 @@ function doCreateMainWindow(initialUrl, initialBounds) {
                 return;
             }
 
+            log.send(logLevels.INFO, 'creating pop-out window url: ' + newWinParsedUrl);
+
             let x = 0;
             let y = 0;
 
@@ -249,6 +253,8 @@ function doCreateMainWindow(initialUrl, initialBounds) {
                 let browserWin = BrowserWindow.fromWebContents(webContents);
 
                 if (browserWin) {
+                    log.send(logLevels.INFO, 'loaded pop-out window url: ' + newWinParsedUrl);
+
                     browserWin.winName = frameName;
 
                     browserWin.once('closed', function () {

package.json

@@ -69,8 +69,6 @@
     "url": "https://support.symphony.com"
   },
   "devDependencies": {
-    "babel-jest": "^19.0.0",
-    "babel-preset-es2015": "^6.24.0",
     "browserify": "^14.1.0",
     "cross-env": "^3.2.4",
     "electron": "1.6.11",

tests/log.test.js

@@ -0,0 +1,56 @@
+const { Logger } = require('../js/log.js');
+
+describe('logger tests', function() {
+    let log;
+
+    beforeEach(function() {
+        // get new rewired version for each test.
+        log = new Logger();
+    });
+
+    it('when no logger registered then queue items', function() {
+        log.send('DEBUG', 'test');
+        log.send('DEBUG', 'test2');
+        let queue = log.logQueue;
+        expect(queue.length).toBe(2);
+    });
+
+    it('flush queue when logger get registered', function() {
+        log.send('DEBUG', 'test');
+        log.send('DEBUG', 'test2');
+
+        let mockWin = {
+            send: jest.fn()
+        };
+
+        log.setLogWindow(mockWin);
+
+        let queue = log.logQueue;
+
+        expect(mockWin.send).toHaveBeenCalled();
+        expect(queue.length).toBe(0);
+    });
+
+    it('send single log msg logger has already been registered', function() {
+        let mockWin = {
+            send: jest.fn()
+        };
+
+        log.setLogWindow(mockWin);
+        log.send('DEBUG', 'test');
+
+        let queue = log.logQueue;
+
+        expect(mockWin.send).toHaveBeenCalled();
+        expect(queue.length).toBe(0);
+    });
+
+    it('should cap at 100 queued log messages', function() {
+        for(let i = 0; i < 110; i++) {
+            log.send('DEBUG', 'test' + i);
+        }
+
+        let queue = log.logQueue;
+        expect(queue.length).toBe(100);
+    })
+});

tests/utils/getCmdLineArg.test.js

@@ -0,0 +1,28 @@
+const getCmdLineArg = require('../../js/utils/getCmdLineArg.js');
+
+describe('getCmdLineArg tests', function() {
+    it('should return no exact match', function() {
+        var result = getCmdLineArg([ 'hello.exe', '--arg1', '--arg2'], '--arg', true);
+        expect(result).toBe(null);
+    });
+
+    it('should return exact match only', function() {
+        var result = getCmdLineArg([ 'hello.exe', '--arg1', '--arg2'], '--arg2', true);
+        expect(result).toBe('--arg2');
+    });
+
+    it('should return starts with match', function() {
+        var result = getCmdLineArg([ 'hello.exe', '--hello=test', '--arg2'], '--hello=');
+        expect(result).toBe('--hello=test');
+    });
+
+    it('should return no match for starts with', function() {
+        var result = getCmdLineArg([ 'hello.exe', '--hello=test', '--arg2'], '--help=');
+        expect(result).toBe(null);
+    });
+
+    it('should return no match invalid argv given', function() {
+        var result = getCmdLineArg('invalid argv', '--help=');
+        expect(result).toBe(null);
+    });
+});