Implemented asynchronous logging (#44)

extension/lib/logger.js

@@ -2,68 +2,85 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
-var { Cc, Ci } = require("chrome");
+Components.utils.import("resource://gre/modules/NetUtil.jsm");
 
+const { Cc, Ci } = require("chrome");
 
-function Logger(aDir) {
-  this._dir = aDir;
+const PERMS_DIRECTORY = parseInt("0777", 8);
+const PERMS_FILE = parseInt("0666", 8);
 
-  this.active = false;
-  this.file = null;
+function Logger(aOptions) {
+  aOptions = aOptions || {};
+  this._dir = aOptions.dir;
+  this._foStream = null;
+  this._file = null;
+  this._active = false;
+
+  // Converter to create input streams out of strings
+  this._converter = Cc["@mozilla.org/intl/scriptableunicodeconverter"]
+                    .createInstance(Ci.nsIScriptableUnicodeConverter);
+  this._converter.charset = "UTF-8";
 }
 
 Logger.prototype = {
-
-
-  prepareFile: function Logger_prepareFile() {
-    if (!this._dir.exists())
-      this._dir.create(Ci.nsIFile.DIRECTORY_TYPE, 0777);
-    else if (!this._dir.isDirectory())
-      throw Error(this._dir.path + " is not a directory.");
-
-    var file = this._dir.clone();
-    file.append(new Date().getTime() + ".log");
-
-    var foStream = Cc["@mozilla.org/network/file-output-stream;1"]
-                   .createInstance(Ci.nsIFileOutputStream);
-    foStream.init(file, 0x02 | 0x08 | 0x20, 0666, 0);
-    this.file = file;
+  get file() {
+    return this._file;
   },
 
-  start: function Logger_start() {
-    if (!this.active) {
-      this.prepareFile();
-      this.active = true;
-      console.debug("Logging to '" + this.file.path + "' started.");
-    }
-  },
+  get active() {
+    return this._active;
+  }
+};
 
-  stop: function Logger_stop() {
-    if (this.active) {
-      this.active = false;
-      console.debug("Logging to '" + this.file.path + "' stopped.");
-    }
-  },
+Logger.prototype.prepareFile = function Logger_prepareFile() {
+  if (!this._dir.exists())
+    this._dir.create(Ci.nsIFile.DIRECTORY_TYPE, PERMS_DIRECTORY);
+  else if (!this._dir.isDirectory())
+    throw Error(this._dir.path + " is not a directory.");
 
-  log: function Logger_log(data) {
-    if (this.active) {
-      var foStream = Cc["@mozilla.org/network/file-output-stream;1"].
-                     createInstance(Ci.nsIFileOutputStream);
+  var file = this._dir.clone();
+  file.append(Date.now() + ".log");
 
-      foStream.init(this.file, 0x02 | 0x08 | 0x10, 0666, 0);
+  this._file = file;
+};
 
-      data.timestamp = new Date().getTime();
-      var message = JSON.stringify(data);
-      console.debug("Logging: '" + message + "'");
+Logger.prototype.start = function Logger_start() {
+  if (!this.active) {
+    this.prepareFile();
+    this._active = true;
+  }
+};
 
-      var converter = Cc["@mozilla.org/intl/converter-output-stream;1"].
-                      createInstance(Ci.nsIConverterOutputStream);
+Logger.prototype.stop = function Logger_stop() {
+  if (this.active) {
+    this._active = false;
+  }
+};
 
-      converter.init(foStream, "UTF-8", 0, 0);
-      converter.writeString(message + '\r\n');
-      converter.close();
-    }
+Logger.prototype.log = function Logger_log(aData, aCallback) {
+  if (this.active) {
+    aData.timestamp = Date.now();
+    var message = JSON.stringify(aData);
+
+    // Create a output stream to write to file
+    var foStream = Cc["@mozilla.org/network/file-output-stream;1"]
+                  .createInstance(Ci.nsIFileOutputStream);
+    foStream.init(this._file, 0x02 | 0x08 | 0x10, PERMS_FILE, foStream.DEFER_OPEN);
+    var iStream = this._converter.convertToInputStream(message + '\r\n');
+
+    // Write asynchronously to buffer;
+    // Input and output streams are closed after write
+    NetUtil.asyncCopy(iStream, foStream, function (status) {
+      if (!Components.isSuccessCode(status)) {
+        var errorMessage = new Error("Error while writing to file: " + status);
+        console.error(errorMessage);
+      }
+
+      if (aCallback && typeof(aCallback) === "function") {
+        aCallback(status);
+      }
+    });
   }
-}
+};
 
 exports.Logger = Logger;

extension/lib/main.js

@@ -35,7 +35,7 @@ exports.main = function (options, callbacks) {
   var dir = Cc["@mozilla.org/file/directory_service;1"]
             .getService(Ci.nsIProperties).get("ProfD", Ci.nsIFile);
   dir.append(self.name);
-  var logger = new Logger(dir);
+  var logger = new Logger({ dir: dir });
 
   var widget = widgets.Widget({
     id: "memchaser-widget",

extension/test/test-logger.js

@@ -1,27 +1,57 @@
 Components.utils.import('resource://gre/modules/Services.jsm');
 
-
 const { Cc, Ci } = require("chrome");
 const { Logger } = require("memchaser/logger")
 
 const dir = Services.dirsvc.get("TmpD", Ci.nsIFile);
 
-
 exports.test_default_to_not_logging = function (test) {
-  var logger = new Logger(dir);
+  var logger = new Logger({ dir: dir });
 
   test.assert(!logger.active);
 }
 
-
 exports.test_start_stop_logging = function (test) {
-  var logger = new Logger(dir);
+  var logger = new Logger({ dir: dir });
 
   logger.start();
   test.assert(logger.active);
 
   logger.stop();
   test.assert(!logger.active);
+}
+
+exports.test_log_and_callback = function (test) {
+  var logger = new Logger({ dir: dir });
+
+  function verifyOutput(status) {
+    var line = {}, lines = [], continueRead;
+    try {
+      // open an input stream from file
+      var istream = Cc["@mozilla.org/network/file-input-stream;1"].
+                    createInstance(Ci.nsIFileInputStream);
+      istream.init(logger.file, 0x01, parseInt("0444",8), 0);
+      istream.QueryInterface(Ci.nsILineInputStream);
+
+      // read lines into array
+      do {
+        continueRead = istream.readLine(line);
+        lines.push(line.value);
+      } while (continueRead);
+    }
+    finally {
+      istream.close();
+      test.assert(lines[0].indexOf(':50') != -1, 'data');
+      test.assert(lines[1].indexOf(':60') != -1, 'data');
+      test.assert(lines[2].indexOf(':70') != -1, 'data');
+      test.done();
+    }
+  }
+
+  logger.start();
+  logger.log({ GC: 50 });
+  logger.log({ GC: 60 });
+  logger.log({ GC: 70 }, verifyOutput);
 
-  logger.file.remove(false);
+  test.waitUntilDone(2000);
 }