Bug 849412 - Functions are logged as "null" in Addon SDK content scr…

…ipts

- Updated the `replacer` for JSON.stringify in order to propagate functions as string only for `console` type of messages
- Added tests

lib/sdk/content/content-worker.js

@@ -70,15 +70,15 @@ const ContentWorker = Object.freeze({
    *              onChromeEvent --> callback registered through pipe.on
    */
   createPipe: function createPipe(emitToChrome) {
-    function onEvent() {
-      // Convert to real array
-      let args = Array.slice(arguments);
+    function onEvent(type, ...args) {
       // JSON.stringify is buggy with cross-sandbox values,
       // it may return "{}" on functions. Use a replacer to match them correctly.
-      function replacer(k, v) {
-        return typeof v === "function" ? undefined : v;
-      }
-      let str = JSON.stringify(args, replacer);
+      let replacer = (k, v) =>
+        typeof(v) === "function"
+          ? (type === "console" ? Function.toString.call(v) : void(0))
+          : v;
+
+      let str = JSON.stringify([type, ...args], replacer);
       emitToChrome(str);
     }
 
@@ -163,7 +163,7 @@ const ContentWorker = Object.freeze({
               fileName: e.fileName,
               lineNumber: e.lineNumber,
               stack: e.stack,
-              name: e.name, 
+              name: e.name,
             };
           }
           pipe.emit('error', wrapper);

lib/sdk/content/sandbox.js

@@ -50,12 +50,18 @@ const WorkerSandbox = Class({
   /**
    * Emit a message to the worker content sandbox
    */
-  emit: function emit(...args) {
+  emit: function emit(type, ...args) {
+    // JSON.stringify is buggy with cross-sandbox values,
+    // it may return "{}" on functions. Use a replacer to match them correctly.
+    let replacer = (k, v) =>
+      typeof(v) === "function"
+        ? (type === "console" ? Function.toString.call(v) : void(0))
+        : v;
+
     // Ensure having an asynchronous behavior
-    let self = this;
-    async(function () {
-      emitToContent(self, JSON.stringify(args, replacer));
-    });
+    async(() =>
+      emitToContent(this, JSON.stringify([type, ...args], replacer))
+    );
   },
 
   /**
@@ -357,14 +363,6 @@ function modelFor (workerSandbox) {
   return sandboxes.get(workerSandbox);
 }
 
-/**
- * JSON.stringify is buggy with cross-sandbox values,
- * it may return '{}' on functions. Use a replacer to match them correctly.
- */
-function replacer (k, v) {
-  return typeof v === 'function' ? undefined : v;
-}
-
 function getUnsafeWindow (win) {
   return win.wrappedJSObject || win;
 }

test/test-content-worker.js

@@ -250,7 +250,7 @@ exports["test:post-json-values-only"] = WorkerTest(
                        "Array is correctly serialized");
       done();
     });
-    // Add a new url property sa the Class function used by 
+    // Add a new url property sa the Class function used by
     // Worker doesn't set enumerables to true for non-functions
     worker._url = DEFAULT_CONTENT_URL;
 
@@ -302,7 +302,7 @@ exports["test:emit-json-values-only"] = WorkerTest(
       fun: function () {},
       dom: browser.contentWindow.document.createElement("div")
     };
-    // Add a new url property sa the Class function used by 
+    // Add a new url property sa the Class function used by
     // Worker doesn't set enumerables to true for non-functions
     worker._url = DEFAULT_CONTENT_URL;
     worker.port.emit("addon-to-content", function () {}, worker, obj, array);
@@ -420,12 +420,12 @@ exports["test:setTimeout works with string argument"] = WorkerTest(
         // since we are inside ContentScriptScope function.
         // i'm NOT putting code-in-string inside code-in-string </YO DAWG>
         window.csVal = 13;
-        setTimeout("self.postMessage([" + 
-                      "csVal, " + 
-                      "window.docVal, " + 
-                      "'ContentWorker' in window, " + 
-                      "'UNWRAP_ACCESS_KEY' in window, " + 
-                      "'getProxyForObject' in window, " + 
+        setTimeout("self.postMessage([" +
+                      "csVal, " +
+                      "window.docVal, " +
+                      "'ContentWorker' in window, " +
+                      "'UNWRAP_ACCESS_KEY' in window, " +
+                      "'getProxyForObject' in window, " +
                     "])", 1);
       },
       contentScriptWhen: "ready",
@@ -467,7 +467,7 @@ exports["test:setInterval async Errors passed to .onError"] = WorkerTest(
       contentScriptWhen: "ready",
       onError: function(err) {
         count++;
-        assert.equal(err.message, "ubik", 
+        assert.equal(err.message, "ubik",
             "error (corectly) propagated  " + count + " time(s)");
         if (count >= 3) done();
       }
@@ -483,11 +483,11 @@ exports["test:setTimeout throws array, passed to .onError"] = WorkerTest(
       contentScript: "setTimeout(function() { throw ['array', 42] }, 1)",
       contentScriptWhen: "ready",
       onError: function(arr) {
-        assert.ok(isArray(arr), 
+        assert.ok(isArray(arr),
             "the type of thrown/propagated object is array");
-        assert.ok(arr.length==2, 
+        assert.ok(arr.length==2,
             "the propagated thrown array is the right length");
-        assert.equal(arr[1], 42, 
+        assert.equal(arr[1], 42,
             "element inside the thrown array correctly propagated");
         done();
       }
@@ -503,15 +503,15 @@ exports["test:setTimeout string arg with SyntaxError to .onError"] = WorkerTest(
       contentScript: "setTimeout('syntax 123 error', 1)",
       contentScriptWhen: "ready",
       onError: function(err) {
-        assert.equal(err.name, "SyntaxError", 
+        assert.equal(err.name, "SyntaxError",
             "received SyntaxError thrown from bad code in string argument to setTimeout");
-        assert.ok('fileName' in err, 
+        assert.ok('fileName' in err,
             "propagated SyntaxError contains a fileName property");
-        assert.ok('stack' in err, 
+        assert.ok('stack' in err,
             "propagated SyntaxError contains a stack property");
-        assert.equal(err.message, "missing ; before statement", 
+        assert.equal(err.message, "missing ; before statement",
             "propagated SyntaxError has the correct (helpful) message");
-        assert.equal(err.lineNumber, 1, 
+        assert.equal(err.lineNumber, 1,
             "propagated SyntaxError was thrown on the right lineNumber");
         done();
       }
@@ -831,45 +831,82 @@ exports['test:conentScriptFile as URL instance'] = WorkerTest(
       window: browser.contentWindow,
       contentScriptFile: url,
       onMessage: function(msg) {
-        assert.equal(msg, "msg from contentScriptFile", 
+        assert.equal(msg, "msg from contentScriptFile",
             "received a wrong message from contentScriptFile");
         done();
       }
     });
   }
 );
 
-exports.testWorkerEvents = WorkerTest(DEFAULT_CONTENT_URL, function (assert, browser, done) {
-  let window = browser.contentWindow;
-  let events = [];
-  let worker = Worker({
-    window: window,
-    contentScript: 'new ' + function WorkerScope() {
-      self.postMessage('start');
-    },
-    onAttach: win => {
-      events.push('attach');
-      assert.pass('attach event called when attached');
-      assert.equal(window, win, 'attach event passes in attached window');
-    },
-    onError: err => {
-      assert.equal(err.message, 'Custom',
-        'Error passed into error event');
-      worker.detach();
-    },
-    onMessage: msg => {
-      assert.pass('`onMessage` handles postMessage')
-      throw new Error('Custom');
-    },
-    onDetach: _ => {
-      assert.pass('`onDetach` called when worker detached');
-      done();
-    }
-  });
-  // `attach` event is called synchronously during instantiation,
-  // so we can't listen to that, TODO FIX?
-  //  worker.on('attach', obj => console.log('attach', obj));
-});
+exports["test:worker events"] = WorkerTest(
+  DEFAULT_CONTENT_URL,
+  function (assert, browser, done) {
+    let window = browser.contentWindow;
+    let events = [];
+    let worker = Worker({
+      window: window,
+      contentScript: 'new ' + function WorkerScope() {
+        self.postMessage('start');
+      },
+      onAttach: win => {
+        events.push('attach');
+        assert.pass('attach event called when attached');
+        assert.equal(window, win, 'attach event passes in attached window');
+      },
+      onError: err => {
+        assert.equal(err.message, 'Custom',
+          'Error passed into error event');
+        worker.detach();
+      },
+      onMessage: msg => {
+        assert.pass('`onMessage` handles postMessage')
+        throw new Error('Custom');
+      },
+      onDetach: _ => {
+        assert.pass('`onDetach` called when worker detached');
+        done();
+      }
+    });
+    // `attach` event is called synchronously during instantiation,
+    // so we can't listen to that, TODO FIX?
+    //  worker.on('attach', obj => console.log('attach', obj));
+  }
+);
 
+exports["test:console method log functions properly"] = WorkerTest(
+  DEFAULT_CONTENT_URL,
+  function(assert, browser, done) {
+    let logs = [];
+
+    let clean = message =>
+          message.trim().
+          replace(/[\r\n]/g, " ").
+          replace(/ +/g, " ");
+
+    let onMessage = (type, message) => logs.push(clean(message));
+    let { loader } = LoaderWithHookedConsole(module, onMessage);
+
+    let worker =  loader.require("sdk/content/worker").Worker({
+      window: browser.contentWindow,
+      contentScript: "new " + function WorkerScope() {
+        console.log(Function);
+        console.log((foo) => foo * foo);
+        console.log(function foo(bar) { return bar + bar });
+
+        self.postMessage();
+      },
+      onMessage: () => {
+        assert.deepEqual(logs, [
+          "function Function() { [native code] }",
+          "(foo) => foo * foo",
+          "function foo(bar) { \"use strict\"; return bar + bar }"
+        ]);
+
+        done();
+      }
+    });
+  }
+);
 
 require("test").run(exports);