Bug 993520: Create a custom console for workers tagged with the inner…

… window ID of the worker's DOM window.

lib/sdk/console/plain-text.js

@@ -12,7 +12,7 @@ const { Cc, Ci, Cu, Cr } = require("chrome");
 const self = require("../self");
 const prefs = require("../preferences/service");
 const { merge } = require("../util/object");
-const { ConsoleAPI } = Cu.import("resource://gre/modules/devtools/Console.jsm");
+const { ConsoleAPI } = Cu.import("resource://gre/modules/devtools/Console.jsm", {});
 
 const DEFAULT_LOG_LEVEL = "error";
 const ADDON_LOG_LEVEL_PREF = "extensions." + self.id + ".sdk.console.logLevel";
@@ -44,12 +44,13 @@ let branch = Cc["@mozilla.org/preferences-service;1"].
 branch.addObserver(ADDON_LOG_LEVEL_PREF, logLevelObserver, true);
 branch.addObserver(SDK_LOG_LEVEL_PREF, logLevelObserver, true);
 
-function PlainTextConsole(print) {
+function PlainTextConsole(print, innerID) {
 
   let consoleOptions = {
     prefix: self.name + ": ",
     maxLogLevel: logLevel,
-    dump: print
+    dump: print,
+    innerID: innerID
   };
   let console = new ConsoleAPI(consoleOptions);
 

lib/sdk/content/sandbox.js

@@ -19,6 +19,7 @@ const { sandbox, evaluate, load } = require('../loader/sandbox');
 const { merge } = require('../util/object');
 const { getTabForContentWindow } = require('../tabs/utils');
 const { getInnerId } = require('../window/utils');
+const { PlainTextConsole } = require('../console/plain-text');
 
 // WeakMap of sandboxes so we can access private values
 const sandboxes = new WeakMap();
@@ -197,8 +198,10 @@ const WorkerSandbox = Class({
     // script
     merge(model, result);
 
+    let console = new PlainTextConsole(null, getInnerId(window));
+
     // Handle messages send by this script:
-    setListeners(this);
+    setListeners(this, console);
 
     // Inject `addon` global into target document if document is trusted,
     // `addon` in document is equivalent to `self` in content script.
@@ -304,7 +307,7 @@ function importScripts (workerSandbox, ...urls) {
   }
 }
 
-function setListeners (workerSandbox) {
+function setListeners (workerSandbox, console) {
   let { worker } = modelFor(workerSandbox);
   // console.xxx calls
   workerSandbox.on('console', function consoleListener (kind, ...args) {

lib/sdk/test/loader.js

@@ -8,7 +8,7 @@ const { resolveURI, Require,
         unload, override, descriptor } = require('../../toolkit/loader');
 const { ensure } = require('../system/unload');
 const addonWindow = require('../addon/window');
-const { PlainTextConsole } = require("sdk/console/plain-text");
+const { PlainTextConsole } = require('sdk/console/plain-text');
 
 let defaultGlobals = override(require('../system/globals'), {
   console: console
@@ -43,33 +43,43 @@ function CustomLoader(module, globals, packaging, overrides={}) {
 };
 exports.Loader = CustomLoader;
 
+function HookedPlainTextConsole(hook, print, innerID) {
+  this.log = hook.bind(null, "log", innerID);
+  this.info = hook.bind(null, "info", innerID);
+  this.warn = hook.bind(null, "warn", innerID);
+  this.error = hook.bind(null, "error", innerID);
+  this.debug = hook.bind(null, "debug", innerID);
+  this.exception = hook.bind(null, "exception", innerID);
+  this.time = hook.bind(null, "time", innerID);
+  this.timeEnd = hook.bind(null, "timeEnd", innerID);
+
+  this.__exposedProps__ = {
+    log: "rw", info: "rw", warn: "rw", error: "rw", debug: "rw",
+    exception: "rw", time: "rw", timeEnd: "rw"
+  };
+}
+
 // Creates a custom loader instance whose console module is hooked in order
 // to avoid printing messages to the console, and instead, expose them in the
 // returned `messages` array attribute
 exports.LoaderWithHookedConsole = function (module, callback) {
   let messages = [];
-  function hook(msg) {
-    messages.push({type: this, msg: msg});
+  function hook(type, innerID, msg) {
+    messages.push({ type: type, msg: msg, innerID: innerID });
     if (callback)
-      callback(this, msg);
+      callback(type, msg, innerID);
   }
+
   return {
     loader: CustomLoader(module, {
-      console: {
-        log: hook.bind("log"),
-        info: hook.bind("info"),
-        warn: hook.bind("warn"),
-        error: hook.bind("error"),
-        debug: hook.bind("debug"),
-        exception: hook.bind("exception"),
-        time: hook.bind("time"),
-        timeEnd: hook.bind("timeEnd"),
-        __exposedProps__: {
-          log: "rw", info: "rw", warn: "rw", error: "rw", debug: "rw",
-          exception: "rw", time: "rw", timeEnd: "rw"
+      console: new HookedPlainTextConsole(hook, null, null)
+    }, override(require("@loader/options"), {
+      modules: {
+        'sdk/console/plain-text': {
+          PlainTextConsole: HookedPlainTextConsole.bind(null, hook)
         }
       }
-    }),
+    })),
     messages: messages
   };
 }
@@ -94,25 +104,19 @@ exports.LoaderWithHookedConsole2 = function (module, callback) {
 // console message type and message and if it returns false the message will
 // not be logged normally
 exports.LoaderWithFilteredConsole = function (module, callback) {
-  function hook(msg) {
-    if (callback && callback(this, msg) == false)
+  function hook(type, innerID, msg) {
+    if (callback && callback(type, msg, innerID) == false)
       return;
-    console[this](msg);
+    console[type](msg);
   }
+
   return CustomLoader(module, {
-    console: {
-      log: hook.bind("log"),
-      info: hook.bind("info"),
-      warn: hook.bind("warn"),
-      error: hook.bind("error"),
-      debug: hook.bind("debug"),
-      exception: hook.bind("exception"),
-      time: hook.bind("time"),
-      timeEnd: hook.bind("timeEnd"),
-      __exposedProps__: {
-        log: "rw", info: "rw", warn: "rw", error: "rw", debug: "rw",
-        exception: "rw", time: "rw", timeEnd: "rw"
+    console: new HookedPlainTextConsole(hook, null, null)
+  }, override(require("@loader/options"), {
+    modules: {
+      'sdk/console/plain-text': {
+        PlainTextConsole: HookedPlainTextConsole.bind(null, hook)
       }
     }
-  });
+  }));
 }

test/test-page-mod.js

@@ -24,6 +24,7 @@ const { isTabPBSupported, isWindowPBSupported, isGlobalPBSupported } = require('
 const promise = require("sdk/core/promise");
 const { pb } = require('./private-browsing/helper');
 const { URL } = require("sdk/url");
+const { LoaderWithHookedConsole } = require('sdk/test/loader');
 
 const { waitUntil } = require("sdk/test/utils");
 const data = require("./fixtures");
@@ -1531,6 +1532,41 @@ exports.testDetachOnUnload = function(assert, done) {
   })
 }
 
+exports.testConsole = function(assert, done) {
+  let innerID;
+  const TEST_URL = 'data:text/html;charset=utf-8,console';
+  const { loader } = LoaderWithHookedConsole(module, onMessage);
+  const { PageMod } = loader.require('sdk/page-mod');
+  const system = require("sdk/system/events");
+
+  let seenMessage = false;
+  function onMessage(type, msg, msgID) {
+    seenMessage = true;
+    innerID = msgID;
+  }
+
+  let mod = PageMod({
+    include: TEST_URL,
+    contentScriptWhen: "ready",
+    contentScript: Isolate(function() {
+      console.log("Hello from the page mod");
+      self.port.emit("done");
+    }),
+    onAttach: function(worker) {
+      worker.port.on("done", function() {
+        let window = getTabContentWindow(tab);
+        let id = getInnerId(window);
+        assert.ok(seenMessage, "Should have seen the console message");
+        assert.equal(innerID, id, "Should have seen the right inner ID");
+        closeTab(tab);
+        done();
+      });
+    },
+  });
+
+  let tab = openTab(getMostRecentBrowserWindow(), TEST_URL);
+}
+
 exports.testSyntaxErrorInContentScript = function(assert, done) {
   const url = "data:text/html;charset=utf-8,testSyntaxErrorInContentScript";
   let hitError = null;

test/test-plain-text-console.js

@@ -7,6 +7,7 @@ const { id, name } = require("sdk/self");
 const { Cc, Cu, Ci } = require("chrome");
 const { loadSubScript } = Cc['@mozilla.org/moz/jssubscript-loader;1'].
                      getService(Ci.mozIJSSubScriptLoader);
+const system = require("sdk/system/events");
 
 const ADDON_LOG_LEVEL_PREF = "extensions." + id + ".sdk.console.logLevel";
 const SDK_LOG_LEVEL_PREF = "extensions.sdk.console.logLevel";
@@ -230,6 +231,30 @@ exports.testPlainTextConsoleBoundMethods = function(assert) {
   restorePrefs();
 };
 
+exports.testConsoleInnerID = function(assert) {
+  let Console = require("sdk/console/plain-text").PlainTextConsole;
+  let { log, info, warn, error, debug, exception, trace } = new Console(function() {}, "test ID");
+
+  let messages = [];
+  function onMessage({ subject }) {
+    let message = subject.wrappedJSObject;
+    messages.push({ msg: message.arguments[0], type: message.level, innerID: message.innerID });
+  }
+
+  system.on("console-api-log-event", onMessage);
+
+  log("Test log");
+  warn("Test warning");
+  error("Test error");
+
+  assert.equal(messages.length, 3, "Should see 3 log events");
+  assert.deepEqual(messages[0], { msg: "Test log", type: "log", innerID: "test ID" }, "Should see the right event");
+  assert.deepEqual(messages[1], { msg: "Test warning", type: "warn", innerID: "test ID" }, "Should see the right event");
+  assert.deepEqual(messages[2], { msg: "Test error", type: "error", innerID: "test ID" }, "Should see the right event");
+
+  system.off("console-api-log-event", onMessage);
+};
+
 function restorePrefs() {
   if (HAS_ORIGINAL_ADDON_LOG_LEVEL)
     prefs.set(ADDON_LOG_LEVEL_PREF, ORIGINAL_ADDON_LOG_LEVEL);

test/test-test-loader.js

@@ -48,12 +48,12 @@ exports["test LoaderWithHookedConsole"] = function (assert) {
   console.debug("5th");
   console.exception("6th");
   assert.equal(messages.length, 6, "Got all console messages");
-  assert.deepEqual(messages[0], {type: "log", msg: "1st"}, "Got log");
-  assert.deepEqual(messages[1], {type: "error", msg: "2nd"}, "Got error");
-  assert.deepEqual(messages[2], {type: "warn", msg: "3rd"}, "Got warn");
-  assert.deepEqual(messages[3], {type: "info", msg: "4th"}, "Got info");
-  assert.deepEqual(messages[4], {type: "debug", msg: "5th"}, "Got debug");
-  assert.deepEqual(messages[5], {type: "exception", msg: "6th"}, "Got exception");
+  assert.deepEqual(messages[0], {type: "log", msg: "1st", innerID: null}, "Got log");
+  assert.deepEqual(messages[1], {type: "error", msg: "2nd", innerID: null}, "Got error");
+  assert.deepEqual(messages[2], {type: "warn", msg: "3rd", innerID: null}, "Got warn");
+  assert.deepEqual(messages[3], {type: "info", msg: "4th", innerID: null}, "Got info");
+  assert.deepEqual(messages[4], {type: "debug", msg: "5th", innerID: null}, "Got debug");
+  assert.deepEqual(messages[5], {type: "exception", msg: "6th", innerID: null}, "Got exception");
   assert.equal(count, 6, "Called for all messages");
 };