refactor(@embark/core): make logger async when writing to log file

packages/core/logger/package.json

@@ -45,6 +45,7 @@
     "extends": "../../../.eslintrc.json"
   },
   "dependencies": {
+    "async": "2.6.1",
     "@babel/runtime-corejs3": "7.8.3",
     "colors": "1.4.0",
     "core-js": "3.6.4",

packages/core/logger/src/index.js

@@ -1,3 +1,4 @@
+const async = require('async');
 require('colors');
 const fs = require('fs');
 const date = require('date-and-time');
@@ -19,10 +20,11 @@ export class Logger {
     this.events = options.events || {emit: function(){}};
     this.logLevel = options.logLevel || 'info';
     this._logFunction = options.logFunction || console.log;
+    this.fs = options.fs || fs;
     this.logFunction = function(...args) {
       const color = args[args.length - 1];
       args.splice(args.length - 1, 1);
-      this._logFunction(...args.filter(arg => arg !== undefined && arg !== null).map(arg => {
+      this._logFunction(...args.filter(arg => arg ?? false).map(arg => {
         if (color) {
           return typeof arg === 'object' ? util.inspect(arg, 2)[color] : arg[color];
         }
@@ -30,11 +32,28 @@ export class Logger {
       }));
     };
     this.logFile = options.logFile;
+
+    this.writeToFile = async.cargo((tasks, callback) => {
+      if (!this.logFile) {
+        return callback();
+      }
+      let logs = '';
+      let origin = "[" + ((new Error().stack).split("at ")[3]).trim() + "]";
+      tasks.forEach(task => {
+        logs += `[${date.format(new Date(), DATE_FORMAT)}] ${task.prefix} ${task.args}\n`;
+      });
+      this.fs.appendFile(this.logFile, `\n${origin} ${logs}`, err => {
+        if (err) {
+          this.logFunction(`There was an error writing to the log file: ${err}`, 'red');
+          return callback(err);
+        }
+        callback();
+      });
+    });
   }
 
-
   registerAPICall(plugins) {
-    let plugin = plugins.createPlugin('dashboard', {});
+    let plugin = plugins.createPlugin('logger', {});
     plugin.registerAPICall(
       'ws',
       '/embark-api/logs',
@@ -47,68 +66,99 @@ export class Logger {
     );
   }
 
-  writeToFile(...args) {
-    if (!this.logFile) {
-      return;
-    }
-
-    let origin = "[" + ((new Error().stack).split("at ")[3]).trim() + "]";
-
-    const formattedDate = [`[${date.format(new Date(), DATE_FORMAT)}]`]; // adds a timestamp to the logs in the logFile
-    fs.appendFileSync(this.logFile, "\n" + formattedDate.concat(origin, args).join(' '));
-  }
-
   error(...args) {
     if (!args.length || !(this.shouldLog('error'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "error", args);
-    this.logFunction(...Array.from(args), 'red');
-    this.writeToFile("[error]: ", args);
+    this.logFunction(...args, 'red');
+    this.writeToFile.push({ prefix: "[error]: ", args }, callback);
   }
 
   warn(...args) {
     if (!args.length || !(this.shouldLog('warn'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "warn", args);
-    this.logFunction(...Array.from(args), 'yellow');
-    this.writeToFile("[warning]: ", args);
+    this.logFunction(...args, 'yellow');
+    this.writeToFile.push({ prefix: "[warning]: ", args }, callback);
   }
 
   info(...args) {
     if (!args.length || !(this.shouldLog('info'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "info", args);
-    this.logFunction(...Array.from(args), 'green');
-    this.writeToFile("[info]: ", args);
+    this.logFunction(...args, 'green');
+    this.writeToFile.push({ prefix: "[info]: ", args }, callback);
   }
 
   consoleOnly(...args) {
     if (!args.length || !(this.shouldLog('info'))) {
       return;
     }
-    this.logFunction(...Array.from(args), 'green');
-    this.writeToFile("[consoleOnly]: ", args);
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
+    this.logFunction(...args, 'green');
+    this.writeToFile.push({prefix: "[consoleOnly]: ", args }, callback);
   }
 
   debug(...args) {
     if (!args.length || !(this.shouldLog('debug'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "debug", args);
-    this.logFunction(args, null);
-    this.writeToFile("[debug]: ", args);
+    this.logFunction(...args, null);
+    this.writeToFile.push({ prefix: "[debug]: ", args }, callback);
   }
 
   trace(...args) {
     if (!args.length || !(this.shouldLog('trace'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "trace", args);
-    this.logFunction(args, null);
-    this.writeToFile("[trace]: ", args);
+    this.logFunction(...args, null);
+    this.writeToFile.push({ prefix: "[trace]: ", args }, callback);
   }
 
   dir(...args) {
@@ -116,9 +166,16 @@ export class Logger {
     if (!txt || !(this.shouldLog('info'))) {
       return;
     }
+
+    let callback = () => {};
+    if (typeof args[args.length - 1] === 'function') {
+      callback = args[args.length - 1];
+      args.splice(args.length - 1, 1);
+    }
+
     this.events.emit("log", "dir", txt);
     this.logFunction(txt, null);
-    this.writeToFile("[dir]: ", args);
+    this.writeToFile({ prefix: "[dir]: ", args }, callback);
   }
 
   shouldLog(level) {
@@ -126,3 +183,4 @@ export class Logger {
     return (logLevels.indexOf(level) <= logLevels.indexOf(this.logLevel));
   }
 }
+

packages/core/logger/test/logger.spec.js

@@ -11,14 +11,27 @@ describe('core/logger', () => {
 
   let logger, testLogFn, logFile;
 
+  const fsMock = {
+    logs: {},
+    appendFile: (file, content, callback) => {
+      if (!fsMock.logs[file]) {
+        fsMock.logs[file] = [];
+      }
+      fsMock.logs[file].push(content);
+      callback();
+    }
+  };
+
   beforeEach(() => {
     logFile = tmp.fileSync();
+    fsMock[logFile.name] = [];
 
     testLogFn = sinon.fake();
     logger = new Logger({
       events: embark.events,
       logFunction: testLogFn,
-      logFile: logFile.name
+      logFile: logFile.name,
+      fs: fsMock
     });
   });
 
@@ -41,10 +54,16 @@ describe('core/logger', () => {
     assert(testLogFn.calledWith('\u001b[31mHello world\u001b[39m'));
   });
 
-  test('it should write logs to log file', () => {
-    logger.info('Some test log');
-    const logs = fs.readFileSync(logFile.name, 'utf8')
-    assert.ok(logs.indexOf('[info]:  Some test log') > -1);
+  test('it should write logs to log file', (done) => {
+    const stats = fs.statSync(logFile.name);
+    logger.info('Some test log', () => {
+      fsMock.logs[logFile.name].forEach(entry => {
+        if (entry.indexOf('[info]:  Some test log') > -1) {
+          assert.ok(true);
+        }
+      });
+      done();
+    });
   });
 
   test('it should not log if log method level is higher than configured log level', () => {