1168872 - Support for server side logging

Status: RESOLVED FIXED

(DevTools :: Console, defect)

Description

[Jan Honza Odvarko [:Honza] (always need-info? me)]

This is another firebug gap related feature that should allow sending logs from the server (HTTP server) to the Console panel. Logs should be sent over HTTP headers.

Here is the original issue reported for Firebug
https://github.com/firebug/firebug.next/issues/23

We might be interested in supporting existing protocol:
http://craig.is/writing/chrome-logger


Honza

Comment 1

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-1.patch

I am attaching first try patch to get some feedback:

Some comments:

* There is a new backend actor that looks for server side logs in HTTP headers (actors/server-logger.js)

* There is a helper HTTP observer that runs in the parent process and listens for HTTP events - used only if e10s is enabled (actors/server-logger-monitor).

* There are new filters in the Console panel toolbar and also new prefs. I didn't change the MESSAGE_PREFERENCE_KEYS, should I?

* The feature is done under browser/devtools/webconsole/server-logging. There is one file currently, but there will be more in the future. Also tests will be under server-logging/test dir.

* The backend actor is attached when the Console panel is ready, but I think it would be better if there is a way how to plugin into the panel open method, so the "ready" event is sent when the actor is actually attached in the backend - but keep the implementation/registration within the server-logging dir.

* I am using "debug:server-logger" ID for child/parent process communication. Is there any syntax for these IDs, so they are unique enugh?

* There is a little module with "Trace" object implementation. This is an experiment related to bug 1171927. This won't be part of the final patch, but feedback would be already nice.

* A test page: http://janodvarko.cz/test/serverlogging/test1.html

* All needs deep testing and unit tests yet.

--

Jeff: what do you think about the UI/UX? A screenshot: http://snag.gy/CzjU9.jpg

Alex: Am I using the right approach for the actor and child/parent process communication stuff?

Honza

Comment 2

[Jeff Griffiths (:canuckistani) (:⚡︎)]

(In reply to Jan Honza Odvarko [:Honza] from comment #1)

> Jeff: what do you think about the UI/UX? A screenshot:
> http://snag.gy/CzjU9.jpg

Generally it looks good. Is it intentional to have all the log entries be red? Shouldn't they be styled the same as the log levels for client side logging?

Should there be some visual cue that a given log is from the server?

Comment 3

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-2.patch

(In reply to Jeff Griffiths (:canuckistani) from comment #2)
> Generally it looks good. Is it intentional to have all the log entries be
> red? Shouldn't they be styled the same as the log levels for client side
> logging?
> 
> Should there be some visual cue that a given log is from the server?
Yes fixed.
- The style is now derived from standard client side logs
- The left side indent (at the beginning of the log row) is now green as well as the corresponding filter button icon.

A screenshot: http://snag.gy/2Zowp.jpg


Alex: the patch is updated (including the missing backend actors).

Honza

Comment 4

[Alexandre Poirot [:ochameau]]

Comment on attachment 8615976 [details] [diff] [review]
bug1168872-1.patch

Review of attachment 8615976 [details] [diff] [review]:
-----------------------------------------------------------------

First batch of comments before the actor modules were added.

::: browser/app/profile/firefox.js
@@ +1561,5 @@
>  pref("devtools.webconsole.filter.windowlessworkers", false);
> +pref("devtools.webconsole.filter.servererror", true);
> +pref("devtools.webconsole.filter.serverwarn", true);
> +pref("devtools.webconsole.filter.serverinfo", true);
> +pref("devtools.webconsole.filter.serverlog", true);

nit: I would have used devtools.webconsole.filter.server.xxx

::: browser/devtools/shared/protocol-utils.js
@@ +49,5 @@
> +    });
> +  });
> +
> +  return deferred.promise;
> +}

I do not see this module being used anywhere, but that looks super useful!!

::: browser/devtools/webconsole/server-logging/main.js
@@ +21,5 @@
> +   */
> +  onInitialize: function(eventId, toolbox) {
> +    Trace.sysout("ServerLogging.onInitialize;", toolbox);
> +
> +    toolbox.getPanelWhenReady("webconsole").then(panel => {

Doesn't that fail when we open the toolbox with any other tool (like opening the toolbox directly to the inspector)?
Shouldn't we connect this code only into webconsole codepath rather than toolbox?

@@ +56,5 @@
> +      if (!front) {
> +        front = ServerLoggerFront(client, form);
> +      }
> +
> +      return front.attach().then(() => {

I'm wondering...
Wouldn't it be easier to plug the actor code into TabActor.onAttach,
rather than doing this from the client.
It seems to be something quite generic, many actors would do.

In TabActor._attach, at the end, we could emit a "attach" event (like navigate or window-ready)
and then, each actor would register listeners in their constructor and so, listen for the TabActor attach request instead.

Comment 5

[Alexandre Poirot [:ochameau]]

Comment on attachment 8616629 [details] [diff] [review]
bug1168872-2.patch

Review of attachment 8616629 [details] [diff] [review]:
-----------------------------------------------------------------

I mostly looked at client/actor stuff, not the specifics of this patch (http listening).
It looks good overall, just various minor comments.

::: toolkit/devtools/server/actors/server-logger-monitor.js
@@ +92,5 @@
> +    }
> +
> +    this.detach(event);
> +
> +    this.messageManagers.delete(mm);

I think you can move the messageManagers.delate to detach (as we don't expect to use the monitor after detach, and will recreate the parent helper and re-attach if the actor attach again).
Then onDisconnectChild will just call detach.

@@ +120,5 @@
> +    Trace.sysout("ServerLoggerMonitor.onAttachChild; " +
> +      ", win ID: " + winId + ", childId " + actorId +
> +      ", child connId: " + childConnId, event);
> +
> +    // Collect child loggers. The 'target' (XULElement) represents the

The target is XULElement on firefox e10s (xul:browser), but it won't be that on b2g (will be html:iframe).
Better describe it as the frame element where the window/document lives.

@@ +167,5 @@
> +      return;
> +    }
> +
> +    let winId = WindowUtils.getOuterId(win);
> +    let entry = this.targets.get(winId);

Did you tested that on b2g... I'm wondering if outer window id/getTopFrameForRequest works fine on it?

@@ +178,5 @@
> +    if (!entry.target) {
> +      Trace.sysout("ServerLoggerMonitor.onExamineResponse; ERROR no target! " +
> +        entry.actorId);
> +      return;
> +    }

Does that happen sometimes??

@@ +185,5 @@
> +    if (!messageManager) {
> +      Trace.sysout("ServerLoggerMonitor.onExamineResponse; ERROR no " +
> +        "message manager! " + entry.actorId);
> +      return;
> +    }

Same question?

::: toolkit/devtools/server/actors/server-logger.js
@@ +77,5 @@
> +
> +    // xxxHonza: what is this?
> +    if (typeof sendAsyncMessage == "function") {
> +      sendAsyncMessage("http-monitor:shutdown");
> +    }

Yes. What is this? Where sendAsyncMessage comes from?!

@@ +92,5 @@
> +      ", " + this.actorID, arguments);
> +
> +    if (this.state === "attached") {
> +      this.detach();
> +    }

I imagine we can just call this.destroy(), destroy already does the state == attached check.

@@ +180,5 @@
> +    // the parent process.
> +    addMessageListener("debug:server-logger", this.onExamineHeaders);
> +
> +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> +    let win = this.parent._originalWindow;

You are using parent.window in sendMessage, but not in attachParentProcess/onExamineResponse.
Is there any particular reason to do so? It basically means ignoring iframe switching?!

@@ +181,5 @@
> +    addMessageListener("debug:server-logger", this.onExamineHeaders);
> +
> +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> +    let win = this.parent._originalWindow;
> +    let winId = win ? WindowUtils.getOuterId(win) : null;

Do you hava cases where win is null?
It looks like the monitor will just ignore everyhing if we pass a null winId,
then, is that a point to even spawn something in the parent??

@@ +187,5 @@
> +      method: "attachChild",
> +      actorId: this.actorID,
> +      winId: winId,
> +      connId: this.conn.prefix,
> +    });

Note that, if you want, you can improve DebuggerServer.setupInParent in order to also accept an `arguments`/`setupParentArguments` attribute, that would allow to pass options to the setupParent function...
It would allow to get rid of the additional "debug:server-logger" message.

::: toolkit/devtools/shared/trace.js
@@ +24,5 @@
> +      // This should go away as soon as the browser console is adopted
> +      // for tracing.
> +      let scope = {};
> +      Cu["import"]("resource://fbtrace/firebug-trace-service.js", scope);
> +      let FBTrace = scope.traceConsoleService.getTracer("", sendSyncMessage);

You should lazy define that once instead of doing all that on each log!
sysout may be called many times and is worth optimizing.

Comment 6

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-3.patch

(In reply to Alexandre Poirot [:ochameau] from comment #4)
> ::: browser/app/profile/firefox.js
> @@ +1561,5 @@
> >  pref("devtools.webconsole.filter.windowlessworkers", false);
> > +pref("devtools.webconsole.filter.servererror", true);
> > +pref("devtools.webconsole.filter.serverwarn", true);
> > +pref("devtools.webconsole.filter.serverinfo", true);
> > +pref("devtools.webconsole.filter.serverlog", true);
> 
> nit: I would have used devtools.webconsole.filter.server.xxx
I've been following syntax of the existing prefs that are also
not using an extra dot (e.g. csslog, csserror, netwarn, etc.)
So, I kept this in the patch.

> I do not see this module being used anywhere, but that looks super useful!!
Remove for now, I can commit as soon as there is an opportunity!

> ::: browser/devtools/webconsole/server-logging/main.js
> @@ +21,5 @@
> > +   */
> > +  onInitialize: function(eventId, toolbox) {
> > +    Trace.sysout("ServerLogging.onInitialize;", toolbox);
> > +
> > +    toolbox.getPanelWhenReady("webconsole").then(panel => {
> 
> Doesn't that fail when we open the toolbox with any other tool (like opening
> the toolbox directly to the inspector)?
> Shouldn't we connect this code only into webconsole codepath rather than
> toolbox?
Yes, done.


> @@ +56,5 @@
> > +      if (!front) {
> > +        front = ServerLoggerFront(client, form);
> > +      }
> > +
> > +      return front.attach().then(() => {
> 
> I'm wondering...
> Wouldn't it be easier to plug the actor code into TabActor.onAttach,
> rather than doing this from the client.
> It seems to be something quite generic, many actors would do.
> 
> In TabActor._attach, at the end, we could emit a "attach" event (like
> navigate or window-ready)
> and then, each actor would register listeners in their constructor and so,
> listen for the TabActor attach request instead.
I've reused the existing WebConsoleActor in the new patch, so this isn't needed anymore.


(In reply to Alexandre Poirot [:ochameau] from comment #5)
> Comment on attachment 8616629 [details] [diff] [review]
> ::: toolkit/devtools/server/actors/server-logger-monitor.js
> @@ +92,5 @@
> > +    }
> > +
> > +    this.detach(event);
> > +
> > +    this.messageManagers.delete(mm);
> 
> I think you can move the messageManagers.delate to detach (as we don't
> expect to use the monitor after detach, and will recreate the parent helper
> and re-attach if the actor attach again).
> Then onDisconnectChild will just call detach.
Done

> 
> @@ +120,5 @@
> > +    Trace.sysout("ServerLoggerMonitor.onAttachChild; " +
> > +      ", win ID: " + winId + ", childId " + actorId +
> > +      ", child connId: " + childConnId, event);
> > +
> > +    // Collect child loggers. The 'target' (XULElement) represents the
> 
> The target is XULElement on firefox e10s (xul:browser), but it won't be that
> on b2g (will be html:iframe).
> Better describe it as the frame element where the window/document lives.
Description changed and I've been also testing on b2g, code fixed.

> @@ +167,5 @@
> > +      return;
> > +    }
> > +
> > +    let winId = WindowUtils.getOuterId(win);
> > +    let entry = this.targets.get(winId);
> 
> Did you tested that on b2g... I'm wondering if outer window
> id/getTopFrameForRequest works fine on it?
All fixed on b2g

> @@ +178,5 @@
> > +    if (!entry.target) {
> > +      Trace.sysout("ServerLoggerMonitor.onExamineResponse; ERROR no target! " +
> > +        entry.actorId);
> > +      return;
> > +    }
> 
> Does that happen sometimes??
Removed

> @@ +185,5 @@
> > +    if (!messageManager) {
> > +      Trace.sysout("ServerLoggerMonitor.onExamineResponse; ERROR no " +
> > +        "message manager! " + entry.actorId);
> > +      return;
> > +    }
> 
> Same question?
Removed

> ::: toolkit/devtools/server/actors/server-logger.js
> @@ +77,5 @@
> > +
> > +    // xxxHonza: what is this?
> > +    if (typeof sendAsyncMessage == "function") {
> > +      sendAsyncMessage("http-monitor:shutdown");
> > +    }
> 
> Yes. What is this? Where sendAsyncMessage comes from?!
Removed

> 
> @@ +92,5 @@
> > +      ", " + this.actorID, arguments);
> > +
> > +    if (this.state === "attached") {
> > +      this.detach();
> > +    }
> 
> I imagine we can just call this.destroy(), destroy already does the state ==
> attached check.
Fixed

> 
> @@ +180,5 @@
> > +    // the parent process.
> > +    addMessageListener("debug:server-logger", this.onExamineHeaders);
> > +
> > +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> > +    let win = this.parent._originalWindow;
> 
> You are using parent.window in sendMessage, but not in
> attachParentProcess/onExamineResponse.
> Is there any particular reason to do so? It basically means ignoring iframe
> switching?!
Not sure if I understand this, can you please re-check the new patch?

> @@ +181,5 @@
> > +    addMessageListener("debug:server-logger", this.onExamineHeaders);
> > +
> > +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> > +    let win = this.parent._originalWindow;
> > +    let winId = win ? WindowUtils.getOuterId(win) : null;
> 
> Do you hava cases where win is null?
> It looks like the monitor will just ignore everyhing if we pass a null winId,
> then, is that a point to even spawn something in the parent??
The window is null on b2g

> @@ +187,5 @@
> > +      method: "attachChild",
> > +      actorId: this.actorID,
> > +      winId: winId,
> > +      connId: this.conn.prefix,
> > +    });
> 
> Note that, if you want, you can improve DebuggerServer.setupInParent in
> order to also accept an `arguments`/`setupParentArguments` attribute, that
> would allow to pass options to the setupParent function...
> It would allow to get rid of the additional "debug:server-logger" message.
Yup, agree reported as Bug 1173805 

> ::: toolkit/devtools/shared/trace.js
> @@ +24,5 @@
> > +      // This should go away as soon as the browser console is adopted
> > +      // for tracing.
> > +      let scope = {};
> > +      Cu["import"]("resource://fbtrace/firebug-trace-service.js", scope);
> > +      let FBTrace = scope.traceConsoleService.getTracer("", sendSyncMessage);
> 
> You should lazy define that once instead of doing all that on each log!
> sysout may be called many times and is worth optimizing.
Yeah, fixed, but note that I'll remove this part eventually. It's not part of this bug (just testing the API)


----

There are some changes:

- I decided to reuse the WebConsoleActor instead of creating a new one. It fits better into the existing architecture.

- The filtering using the "Server" toolbar button works now. If it's off the backend listener is removed to optimize performance. Also, the logging is off by default.

- A test is included in the patch

- atob and btoa API exposed from DevToolsUtils.jsm module 

- Tested on b2g


Honza

Comment 7

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-4.patch

One forgotten module import fixed (one liner change)
Patch updated.


Honza

Comment 8

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Try:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9cb4a588f1b1

Honza

Comment 9

[Jeff Griffiths (:canuckistani) (:⚡︎)]

(In reply to Jan Honza Odvarko [:Honza] from comment #8)
> Try:
> 
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=9cb4a588f1b1

Looks great!

Comment 10

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Alex: the test (included in the attached patch) is failing in the try-build above. I tried running locally and it only fails on Linux and only if I run the entire browser/devtools/websonsole/test suite.

There is an exception:
Handler function threw an exception: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsISyncMessageSender.sendSyncMessage]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/main.js :: DebuggerServer.setupInParent :: line 817"  data: no]
Stack: DebuggerServer.setupInParent@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/main.js:817:1
ServerLoggingListener<.attachParentProcess@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/toolkit/webconsole/server-logger.js:124:1
ServerLoggingListener<.attach<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/toolkit/webconsole/server-logger.js:98:7
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
ServerLoggingListener<.initialize@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/toolkit/webconsole/server-logger.js:68:5
constructor@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/commonjs/sdk/core/heritage.js:146:23
WCA_onStartListeners@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/actors/webconsole.js:615:15
DSC_onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/main.js:1474:15
ChildDebuggerTransport.prototype.receiveMessage@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/transport/transport.js:742:5


It points to the following code:

  setupInParent: function({ module, setupParent }) {
    if (!this.isInChildProcess) {
      return false;
    }

    let { sendSyncMessage } = DebuggerServer.parentMessageManager;

    return sendSyncMessage("debug:setup-in-parent", {
      module: module,
      setupParent: setupParent
    });
  },

Do you know why "sendSyncMessage" would fail with NS_ERROR_ILLEGAL_VALUE?

Honza

Comment 11

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Panos: is the problem described in comment 10 related to bug 1042253?

Honza

Comment 12

[Panos Astithas (he/him) [:past] (please ni?)]

Bug 1042253 is very old and fixed tests to work in e10s, so I don't see how it is related to the setupInParent API that is more recent. I haven't looked at the patch yet, but I will soon.

Comment 13

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Btw. I believe that the test-failure (comment 10) is related to e10s mode (not to OS). I can reproduce it also on my Win machine.

Honza

Comment 14

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-5.patch

Updated patch (only the helper trace.js module removed, the tracer will be introduced in bug 1171927)

Honza

Comment 15

[Alexandre Poirot [:ochameau]]

You could reproduce it with running it twice, like this:
  ./mach mochitest browser/devtools/webconsole/test/browser_console_server_logging.js --e10s --repeat 2

I don't know why but this modification fixed it:
diff --git a/toolkit/devtools/server/child.js b/toolkit/devtools/server/child.js
index 88cce05..679a4f5 100644
--- a/toolkit/devtools/server/child.js
+++ b/toolkit/devtools/server/child.js
@@ -19,13 +19,13 @@ let chromeGlobal = this;
 
   if (!DebuggerServer.initialized) {
     DebuggerServer.init();
-
-    // message manager helpers provided for actor module parent/child message exchange
-    DebuggerServer.parentMessageManager = {
-      sendSyncMessage: sendSyncMessage,
-      addMessageListener: addMessageListener
-    };
   }
+  // message manager helpers provided for actor module parent/child message exchange
+  DebuggerServer.parentMessageManager = {
+    sendSyncMessage: sendSyncMessage,
+    addMessageListener: addMessageListener,
+    removeMessageListener: removeMessageListener,
+  };
 
   // In case of apps being loaded in parent process, DebuggerServer is already
   // initialized, but child specific actors are not registered.

Comment 16

[Alexandre Poirot [:ochameau]]

That is really unexpected, if such modification is needed, it means that if we close one tab, and open another one, it is going to fail with the same error, like in this test.

Comment 17

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Alexandre Poirot [:ochameau] from comment #16)
> That is really unexpected, if such modification is needed, it means that if
> we close one tab, and open another one, it is going to fail with the same
> error, like in this test.

Thanks Alex for the analyses!

New try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=5913d4f91da8

Alex, should I file a follow-up to improve the change you made?

Honza

Comment 18

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Alex, I am seeing oranges, looks like related to the change?
(toolkit/devtools/server/tests/mochitest/test_director.html passes for me locally)

Honza

Comment 19

[Alexandre Poirot [:ochameau]]

The previous inlined was very hacky.
Here is something better:
diff --git a/toolkit/devtools/server/child.js b/toolkit/devtools/server/child.js
index 88cce05..c6bdc54c 100644
--- a/toolkit/devtools/server/child.js
+++ b/toolkit/devtools/server/child.js
@@ -11,6 +11,8 @@ let chromeGlobal = this;
 // Encapsulate in its own scope to allows loading this frame script
 // more than once.
 (function () {
+  let Cc = Components.classes;
+  let Ci = Components.interfaces;
   let Cu = Components.utils;
   let { devtools } = Cu.import("resource://gre/modules/devtools/Loader.jsm", {});
   const DevToolsUtils = devtools.require("devtools/toolkit/DevToolsUtils.js");
@@ -21,10 +23,9 @@ let chromeGlobal = this;
     DebuggerServer.init();
 
     // message manager helpers provided for actor module parent/child message exchange
-    DebuggerServer.parentMessageManager = {
-      sendSyncMessage: sendSyncMessage,
-      addMessageListener: addMessageListener
-    };
+    let cpmm = Cc["@mozilla.org/childprocessmessagemanager;1"]
+                 .getService(Ci.nsISyncMessageSender);
+    DebuggerServer.parentMessageManager = cpmm;
   }
 
   // In case of apps being loaded in parent process, DebuggerServer is already
diff --git a/toolkit/devtools/server/main.js b/toolkit/devtools/server/main.js
index f18087f..31d8067 100644
--- a/toolkit/devtools/server/main.js
+++ b/toolkit/devtools/server/main.js
@@ -992,7 +992,9 @@ var DebuggerServer = {
         return false;
       }
     };
-    mm.addMessageListener("debug:setup-in-parent", onSetupInParent);
+    let ppmm = Cc["@mozilla.org/parentprocessmessagemanager;1"]
+                 .getService(Ci.nsIMessageListenerManager);
+    ppmm.addMessageListener("debug:setup-in-parent", onSetupInParent);
 
     let onActorCreated = DevToolsUtils.makeInfallible(function (msg) {
       if (msg.json.prefix != prefix) {
@@ -1062,7 +1064,7 @@ var DebuggerServer = {
 
       // Cleanup all listeners
       Services.obs.removeObserver(onMessageManagerClose, "message-manager-close");
-      mm.removeMessageListener("debug:setup-in-parent", onSetupInParent);
+      ppmm.removeMessageListener("debug:setup-in-parent", onSetupInParent);
       if (!actor) {
         mm.removeMessageListener("debug:actor", onActorCreated);
       }



But I'm still surprised it does fail only here, why only here?!
I understand why it fails. We most likely close a tab, where we first evaluated the child.js framescript and its message manager got destroyed. 
And as only director/dynamic actors uses DebuggerServer.parentMessageManager... I get why it fails only for this test. But don't we have another test with similar scenario??
Can't we reproduce it manually easily by opening a tab, then devtools, closing the tab, repeat and see a feature using dynamic actors being broken?

I tried to verify if we cleanup stuff correctly, but I'm not sure we do.
message-manager-close (in main.js, connectToChild) doesn't seem to be called :/

Comment 20

[Alexandre Poirot [:ochameau]]

So we do cleanup stuff correctly for the first frame script. `destroy` inlined function is called in main.js:connectToChild, and that calls `debug:disconnect` listener in child.js. That ends up unregistering message-manager-close listener before it gets a chance to be fired.

There is something wrong in my last patch. The ppmm.addEventListener should be done only once. Not once per child. We should move that to `init` or ensure doing it only once in connectToChild.

Comment 21

[Alexandre Poirot [:ochameau]]

Comment on attachment 8624265 [details] [diff] [review]
bug1168872-5.patch

Review of attachment 8624265 [details] [diff] [review]:
-----------------------------------------------------------------

Here is a lot of comments, but overall this is great.

About e10s. I wish you could do like director actor and what Mike did for storage.
It would be great if you could share the same code between e10s and non-10s.
I'm thinking about server-logger-monitor, that duplicates a bunch of code of server-logger around observer service listening/processing.

As I said in Whistler, I would like to provide a way to spawn actors from an actor.
It would ease supporting these e10s stories...
server-logger would spawn an helper actor no matter if we are in e10s or not,
this helper addon would register listener to the observer service, process them, and pipe them back to server-logger via RDP events. Then the only difference between e10s and non-e10s would be where we evaluate this helper actor.
The benefits are that: 
 - we don't have two very different codepaths
 - we don't have to know anything about message manager

::: browser/devtools/webconsole/console-output.js
@@ +1726,5 @@
> +  // A message for console.table() method (passed in as the first argument)
> +  // isn't supported. This should be fixed.
> +  if (typeof this._arguments[0] == "string") {
> +    this._arguments.shift();
> +  }

That looks unrelated to this bug.

::: browser/devtools/webconsole/test/browser_console_server_logging.js
@@ +24,5 @@
> +    messages: [{
> +      text: "hello from the server",
> +      category: CATEGORY_SERVER,
> +      severity: SEVERITY_LOG,
> +    }],

That would be great to also test the printf like behavior!

::: browser/devtools/webconsole/test/test-console-server-logging.sjs
@@ +12,5 @@
> +
> +  var logData = "eyJ2ZXJzaW9uIjoiNC4xLjAiLCJjb2x1bW5zIjpbImxvZyIsImJhY2t0" +
> +    "cmFjZSIsInR5cGUiXSwicm93cyI6W1tbImhlbGxvIGZyb20gdGhlIHNlcnZlciJdLC" +
> +    "JDOlxcc3JjXFx3d3dcXHNlcnZlcmxvZ2dpbmdcXHRlc3Q3LnBocCA6IDQiLCIiXV0s" +
> +    "InJlcXVlc3RfdXJpIjoiXC93d3dcL3NlcnZlcmxvZ2dpbmdcL3Rlc3Q3LnBocCJ9";

What is that weird binary blob?? Can't we compute it from plain source here?
What does it do?

::: browser/devtools/webconsole/webconsole.js
@@ +706,5 @@
> +      prefs.forEach(pref => {
> +        if (Services.prefs.getBoolPref(this._filterPrefsPrefix + pref)) {
> +          startListener = true;
> +        }
> +      });

At this point, you should be using this.filterPrefs instead of querying the prefs every time. (it will work if you use webconsole button)
If you want to also make it work when manually toggling the pref, you should introduce a pref observer that toggles this.filterPrefs.

@@ +711,5 @@
> +
> +      if (startListener) {
> +        this.webConsoleClient.startListeners(["ServerLogging"], aCallback);
> +      } else {
> +        this.webConsoleClient.stopListeners(["ServerLogging"], aCallback);

We should check if we already started the listener before and only call startListeners/stopListeners accordingly!

::: browser/devtools/webconsole/webconsole.xul
@@ +172,5 @@
>            </toolbarbutton>
> +          <toolbarbutton label="&btnServerLogging.label;" type="menu-button"
> +                         category="server" class="devtools-toolbarbutton webconsole-filter-button"
> +                         tooltiptext="&btnServerLogging.tooltip;"
> +                         accesskey="&btnServerLogging.accesskey3;"

I'm not sure it has to be named accesskey3.
I think we can use accesskey.
The button you copied most likely got its key changed multiple times.

::: toolkit/devtools/DevToolsUtils.jsm
@@ +16,5 @@
>  
>  const { devtools } = Components.utils.import("resource://gre/modules/devtools/Loader.jsm", {});
>  this.DevToolsUtils = devtools.require("devtools/toolkit/DevToolsUtils.js");
> +
> +// Expose also atob and btoa API

You should add an additional comment about why... Something like:
JSM scope is special on b2g. You have to bind the variables you want to expose via `var {foo} = Cu.import(bar)` on `this`.
Defining `foo` in the global scope isn't enough, but just on b2g.
Otherwise we expose atob and btoa from this JSM as SDK modules don't get these methods exposed by default in their global scope.

::: toolkit/devtools/server/actors/webconsole.js
@@ +1458,5 @@
> +  {
> +    // All arguments within the message are converted into debuggees.
> +    // Use the default target: this.window (not the object's global)
> +    // if we are running on B2G.
> +    let useObjectGlobal = !this.parentActor.isRootActor;

I don't get this comment?
1) Why is there anything special on B2G?
2) How isRootActor relates to B2G?
3) What happens if we always use useObjectGlobal=true (default behavior)?

::: toolkit/devtools/webconsole/server-logger-monitor.js
@@ +10,5 @@
> +const {DebuggerServer} = require("devtools/server/main");
> +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> +
> +loader.lazyRequireGetter(this, "WindowUtils", "sdk/window/utils");
> +loader.lazyRequireGetter(this, "Events", "sdk/system/events");

Unfortunately, SDK has a significant memory cost.
Most modules comes with a bunch of JS dependencies that cost quite a lot, by the sole fact of loading modules and sandboxes.

I would suggest you to just use Services.obs instead.
Similar comment about WindowUtils, even if it has less dependencies.

::: toolkit/devtools/webconsole/server-logger.js
@@ +10,5 @@
> +const {Class} = require("sdk/core/heritage");
> +
> +const {DebuggerServer} = require("devtools/server/main");
> +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> +const {atob} = Cu.import("resource://gre/modules/devtools/DevToolsUtils.jsm");

I believe you could also import makeInfallible from the JSM.

@@ +55,5 @@
> +      ", child process: " + DebuggerServer.isInChildProcess, filters);
> +
> +    this.owner = owner;
> +
> +    if (filters) {

It looks like filters is always defined, so we should need this `if`.

@@ +177,5 @@
> +      let winId = WindowUtils.getOuterId(this.window);
> +      if (winId != msg.data.winId) {
> +        return;
> +      }
> +    }

It would better to pass the `winID` to the parent process rather than filtering after we pipe the message back!

@@ +211,5 @@
> +      return;
> +    }
> +
> +    // better variable names for parsedMessages, parsedMessage and msg
> +    // (probably a little piece of refactoring)

Is this a TODO comment?
Could you do this refactoring/renaming and get rid of it?

@@ +315,5 @@
> +
> +  // Server Logs
> +
> +  parse: function(header, value) {
> +    let result = decodeURIComponent(escape(atob(value)));

Do you really need all this? escape and decoreURIComponent after atob?
I would have exception atob to be enough.

Also if you have any (stable) link to refer to that documents this. 
It would be great to mention it there.

@@ +335,5 @@
> +      // new version without label
> +      let newVersion = false;
> +      if (data.columns.indexOf("label") === -1) {
> +        newVersion = true;
> +      }

You do not need this newVersion variable, you can merge the two `if`.

@@ +339,5 @@
> +      }
> +
> +      // if this is the old version do some converting
> +      if (!newVersion) {
> +        let showLabel = label && typeof label === "string";

It may be clearer if you move the `let label = ...` here.

@@ +442,5 @@
> +    // this.conn.send(packet);
> +
> +    // Log into the console using standard API now.
> +    // xxxHonza: custom logging should be implemented
> +    // by {@LoggerFront} object.

What is this LoggerFront? The current code looks good to me.

@@ +443,5 @@
> +
> +    // Log into the console using standard API now.
> +    // xxxHonza: custom logging should be implemented
> +    // by {@LoggerFront} object.
> +    let consoleEvent = clone(packet.message);

Why do you need to clone, it seems simple enough to be just passed as-is?

@@ +444,5 @@
> +    // Log into the console using standard API now.
> +    // xxxHonza: custom logging should be implemented
> +    // by {@LoggerFront} object.
> +    let consoleEvent = clone(packet.message);
> +    consoleEvent.wrappedJSObject = consoleEvent;

I'm not sure you need this anymore if you pass it to the RDP protocol

@@ +452,5 @@
> +
> +    this.owner.onServerLogCall(consoleEvent);
> +
> +    //Services.obs.notifyObservers(consoleEvent,
> +    //  "console-api-log-event", null);

Could you get rid of commented code?

@@ +507,5 @@
> +    if (!specifier) {
> +      break;
> +    }
> +
> +    specifiers.push(specifier);

This code looks unnecessary complex as it is splitted in two steps.
I think it will be much easier if you combine both steps.
i.e. you are building the concatenated string directly from this while loop.
You may not inline everything in the while loop, having a sub function would help reading it.
The important point is that you do not need the intermediate splitLogs and specifiers variables!

Also, I'm wondering... this feature is already implemented in the webconsole. Couldn't we just pass the printf-like string as-is and let the existing console code do this work?
Or, if there is a reason that justify doing this right here and not later, couldn't we share the code?

@@ +559,5 @@
> +          msg.styles.push(null);
> +        }
> +        msg.styles.push(argument);
> +        // Go to next iteration directly.
> +        return;

This comment is weird, is this copy pasted code?
using return or break doesn't make any difference here.

@@ +571,5 @@
> +    rebuiltLogArray.push(concatString);
> +  }
> +
> +  // Prepend the items of the rebuilt log array of the first string
> +  // to the message logs.

This comment isn't clear to me. Is this to support the cases where we pass more arguments to console.log than there is specifiers?
Like: console.log("foo %s", "bar", "xxx"); ?

Comment 22

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 8624265 [details] [diff] [review]
bug1168872-5.patch

Review of attachment 8624265 [details] [diff] [review]:
-----------------------------------------------------------------

I have a bunch of comments and from an architectural point of view I would be happier if we could combine the server logger monitor with the existing network monitor. I understand that this may not be trivial and I'm not sure how familiar you have become with the network monitor, so I'm not going to insist if you don't feel like it, but it would be better both from a performance and a complexity point of view.

::: browser/app/profile/firefox.js
@@ +1595,5 @@
>  pref("devtools.browserconsole.filter.windowlessworkers", true);
> +pref("devtools.browserconsole.filter.servererror", true);
> +pref("devtools.browserconsole.filter.serverwarn", true);
> +pref("devtools.browserconsole.filter.serverinfo", true);
> +pref("devtools.browserconsole.filter.serverlog", true);

These should be false by default. The Browser Console is used to debug the browser, not a server-side app.

::: browser/devtools/webconsole/console-output.js
@@ +1297,5 @@
>  {
>    let options = {
>      className: "cm-s-mozilla",
>      timestamp: packet.timeStamp,
> +    category: packet.category || "webdev",

I think it would be better to always send the category in both cases and still leave the "or" part here for backwards compatibility.

@@ +1723,5 @@
>    this._repeatID.consoleApiLevel = packet.level;
>    this._arguments = packet.arguments;
> +
> +  // A message for console.table() method (passed in as the first argument)
> +  // isn't supported. This should be fixed.

I don't understand this comment. This change modifies the way console.table works for web apps too.

::: browser/devtools/webconsole/webconsole.js
@@ +34,5 @@
>  loader.lazyImporter(this, "VariablesViewController", "resource:///modules/devtools/VariablesViewController.jsm");
>  loader.lazyImporter(this, "PluralForm", "resource://gre/modules/PluralForm.jsm");
>  loader.lazyImporter(this, "gDevTools", "resource:///modules/devtools/gDevTools.jsm");
>  
> +const { setTimeout, clearTimeout } = require("sdk/timers");

You can lazy-load this with loader.lazyRequireGetter().

@@ +661,5 @@
> +      try {
> +        this.filterPrefs[pref] = Services.prefs.getBoolPref(
> +          this._filterPrefsPrefix + pref);
> +      } catch (err) {
> +        Cu.reportError("Pref: " + pref + ", " + err);

What's the purpose of the try/catch block if you are adding the prefs in firefox.js anyway?

@@ +1016,5 @@
> +      clearTimeout(this._updateListenersTimeout);
> +    }
> +
> +    this._updateListenersTimeout = setTimeout(
> +      this._onUpdateListeners, 200);

Why is the timeout needed? In particular, why is the reflow activity listener now updated after the timeout?

::: browser/locales/en-US/chrome/browser/devtools/webConsole.dtd
@@ +79,5 @@
> +<!-- LOCALIZATION NOTE (btnServerLogging): This is used as the text of the
> +  -  the toolbar. It shows or hides messages that the web developer inserted on
> +  -  the page for debugging purposes, using calls on the HTTP server. -->
> +<!ENTITY btnServerLogging.label       "Server">
> +<!ENTITY btnServerLogging.tooltip     "Log messages received from HTTP server">

Nit: I think "Log messages received from a web server" is slightly better.

::: browser/themes/shared/devtools/webconsole.inc.css
@@ +351,5 @@
> +}
> +
> +.message[category=server][severity=info] > .icon::before {
> +  background-position: -36px -36px;
> +}

I think you can combine the last 3 rules with the ones for [category=console].

::: toolkit/devtools/webconsole/server-logger-monitor.js
@@ +55,5 @@
> +
> +  attach: makeInfallible(function({mm, prefix}) {
> +    let size = this.messageManagers.size;
> +
> +    trace.log("ServerLoggerMonitor.attach; " + size, arguments);

I thought we decided to avoid string concatenation in logging calls in order to avoid the perf hit when logging is disabled, didn't we? There are many instances of this pattern in this file.

@@ +109,5 @@
> +        return this.onAttachChild(msg);
> +      case "detachChild":
> +        return this.onDetachChild(msg);
> +      default:
> +        Trace.error("Unknown method name: " + msg.data.method);

What is capital-case 'T' Trace.error? You only define trace.log above.

You can also substitute |method| for |msg.data.method|, since you've already computed it above.

::: toolkit/devtools/webconsole/server-logger.js
@@ +74,5 @@
> +  },
> +
> +  /**
> +   * The destroy is only called automatically by the framework (parent actor)
> +   * if an actor is instantiated by a parent actor.

This listener object is not an actor, so the destroy() method is only executed manually in the owning actor, right?

@@ +85,5 @@
> +  },
> +
> +  /**
> +   * Attach to this actor. Executed when the front (client) is attaching
> +   * to this actor in order to receive server side logs.

Again, this is not an actor and AFAICS the only thing that calls attach() is the listener's initialize() method. Why not inline it in that case?

@@ +108,5 @@
> +
> +  /**
> +   * Detach from this actor. Executed when the front (client) detaches
> +   * from this actor since it isn't interested in server side logs
> +   * any more. So, let's remove the "http-on-examine-response" listener.

Again, since this is not an actor and detach() is only called from destroy(), better inline it.

@@ +183,5 @@
> +    switch (method) {
> +      case "examineHeaders":
> +        return this.onExamineHeaders(msg);
> +      default:
> +        Trace.error("Unknown method name: " + msg.data.method);

Capital 'T' Trace.error again.

@@ +196,5 @@
> +    trace.log("ServerLoggingListener.onExamineHeaders;", headers);
> +
> +    let parsedMessages = [];
> +
> +    headers.forEach(item => {

forEach is slower than for..of and traditional for loops. Since I expect this method to be called often, it would be nice to optimize it.

@@ +288,5 @@
> +      }
> +    }
> +
> +    if (aChannel.loadInfo) {
> +      if (aChannel.loadInfo.contentPolicyType == Ci.nsIContentPolicy.TYPE_BEACON) {

How can a navigator.sendBeacon() call be used to send server-side logging information? I don't think you need this check.

@@ +316,5 @@
> +  // Server Logs
> +
> +  parse: function(header, value) {
> +    let result = decodeURIComponent(escape(atob(value)));
> +    let data = JSON.parse(result);

JSON.parse can throw and this is unsafe header data coming straight from the network, so better guard this with a try/catch block.

Comment 23

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-6.patch

Alex, Panos: thanks for the review!

Updated patch attached.



(In reply to Alexandre Poirot [:ochameau] from comment #21)
> Comment on attachment 8624265 [details] [diff] [review]
> bug1168872-5.patch
> 
> Review of attachment 8624265 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Here is a lot of comments, but overall this is great.
> 
> About e10s. I wish you could do like director actor and what Mike did for
> storage.
> It would be great if you could share the same code between e10s and non-10s.
> I'm thinking about server-logger-monitor, that duplicates a bunch of code of
> server-logger around observer service listening/processing.
> 
> As I said in Whistler, I would like to provide a way to spawn actors from an
> actor.
> It would ease supporting these e10s stories...
> server-logger would spawn an helper actor no matter if we are in e10s or not,
> this helper addon would register listener to the observer service, process
> them, and pipe them back to server-logger via RDP events. Then the only
> difference between e10s and non-e10s would be where we evaluate this helper
> actor.
> The benefits are that: 
>  - we don't have two very different codepaths
>  - we don't have to know anything about message manager
Yes, we need a way to make the code transparent to e10s/non-e10s environments.
Is that ok for you to do it as a follow up? I'd really like to land this and
get some feedback (then we can do improvements step by step).

> 
> ::: browser/devtools/webconsole/console-output.js
> @@ +1726,5 @@
> > +  // A message for console.table() method (passed in as the first argument)
> > +  // isn't supported. This should be fixed.
> > +  if (typeof this._arguments[0] == "string") {
> > +    this._arguments.shift();
> > +  }
> 
> That looks unrelated to this bug.
The server side logging API support also console.table() and expect the
message to be the first argument. So, I was forced to fix it.

> 
> ::: browser/devtools/webconsole/test/browser_console_server_logging.js
> @@ +24,5 @@
> > +    messages: [{
> > +      text: "hello from the server",
> > +      category: CATEGORY_SERVER,
> > +      severity: SEVERITY_LOG,
> > +    }],
> 
> That would be great to also test the printf like behavior!
Good point, done.

> 
> ::: browser/devtools/webconsole/test/test-console-server-logging.sjs
> @@ +12,5 @@
> > +
> > +  var logData = "eyJ2ZXJzaW9uIjoiNC4xLjAiLCJjb2x1bW5zIjpbImxvZyIsImJhY2t0" +
> > +    "cmFjZSIsInR5cGUiXSwicm93cyI6W1tbImhlbGxvIGZyb20gdGhlIHNlcnZlciJdLC" +
> > +    "JDOlxcc3JjXFx3d3dcXHNlcnZlcmxvZ2dpbmdcXHRlc3Q3LnBocCA6IDQiLCIiXV0s" +
> > +    "InJlcXVlc3RfdXJpIjoiXC93d3dcL3NlcnZlcmxvZ2dpbmdcL3Rlc3Q3LnBocCJ9";
> 
> What is that weird binary blob?? Can't we compute it from plain source here?
> What does it do?
True, fixed.

> 
> ::: browser/devtools/webconsole/webconsole.js
> @@ +706,5 @@
> > +      prefs.forEach(pref => {
> > +        if (Services.prefs.getBoolPref(this._filterPrefsPrefix + pref)) {
> > +          startListener = true;
> > +        }
> > +      });
> 
> At this point, you should be using this.filterPrefs instead of querying the
> prefs every time. (it will work if you use webconsole button)
> If you want to also make it work when manually toggling the pref, you should
> introduce a pref observer that toggles this.filterPrefs.
Fixed

> 
> @@ +711,5 @@
> > +
> > +      if (startListener) {
> > +        this.webConsoleClient.startListeners(["ServerLogging"], aCallback);
> > +      } else {
> > +        this.webConsoleClient.stopListeners(["ServerLogging"], aCallback);
> 
> We should check if we already started the listener before and only call
> startListeners/stopListeners accordingly!

Note that the server side is already checking whether the listener is started or not. I think that checking and synchronizing the state on the client brings complexity (e.g. an error handling) and even if it would represent an optimization in terms on sent packets (one packet I guess) I think it isn't worth it. Also note that the reflow activity listener does it the same way. If still think this is needed, I'll do a follow up.

> 
> ::: browser/devtools/webconsole/webconsole.xul
> @@ +172,5 @@
> >            </toolbarbutton>
> > +          <toolbarbutton label="&btnServerLogging.label;" type="menu-button"
> > +                         category="server" class="devtools-toolbarbutton webconsole-filter-button"
> > +                         tooltiptext="&btnServerLogging.tooltip;"
> > +                         accesskey="&btnServerLogging.accesskey3;"
> 
> I'm not sure it has to be named accesskey3.
> I think we can use accesskey.
> The button you copied most likely got its key changed multiple times.
Fixed

> 
> ::: toolkit/devtools/DevToolsUtils.jsm
> @@ +16,5 @@
> >  
> >  const { devtools } = Components.utils.import("resource://gre/modules/devtools/Loader.jsm", {});
> >  this.DevToolsUtils = devtools.require("devtools/toolkit/DevToolsUtils.js");
> > +
> > +// Expose also atob and btoa API
> 
> You should add an additional comment about why... Something like:
> JSM scope is special on b2g. You have to bind the variables you want to
> expose via `var {foo} = Cu.import(bar)` on `this`.
> Defining `foo` in the global scope isn't enough, but just on b2g.
> Otherwise we expose atob and btoa from this JSM as SDK modules don't get
> these methods exposed by default in their global scope.
Fixed (I used your description)

> 
> ::: toolkit/devtools/server/actors/webconsole.js
> @@ +1458,5 @@
> > +  {
> > +    // All arguments within the message are converted into debuggees.
> > +    // Use the default target: this.window (not the object's global)
> > +    // if we are running on B2G.
> > +    let useObjectGlobal = !this.parentActor.isRootActor;
> 
> I don't get this comment?
> 1) Why is there anything special on B2G?
> 2) How isRootActor relates to B2G?
> 3) What happens if we always use useObjectGlobal=true (default behavior)?
Hm... It should probably have been e10s not B2G.
It's about the right global scope for arguments (js objects) passed into console.log API on the server side. In order to send them back to the client we need to make debuggees (using the right global).
Comment updated.

> 
> ::: toolkit/devtools/webconsole/server-logger-monitor.js
> @@ +10,5 @@
> > +const {DebuggerServer} = require("devtools/server/main");
> > +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> > +
> > +loader.lazyRequireGetter(this, "WindowUtils", "sdk/window/utils");
> > +loader.lazyRequireGetter(this, "Events", "sdk/system/events");
> 
> Unfortunately, SDK has a significant memory cost.
> Most modules comes with a bunch of JS dependencies that cost quite a lot, by
> the sole fact of loading modules and sandboxes.
> 
> I would suggest you to just use Services.obs instead.
> Similar comment about WindowUtils, even if it has less dependencies.
Done

> 
> ::: toolkit/devtools/webconsole/server-logger.js
> @@ +10,5 @@
> > +const {Class} = require("sdk/core/heritage");
> > +
> > +const {DebuggerServer} = require("devtools/server/main");
> > +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> > +const {atob} = Cu.import("resource://gre/modules/devtools/DevToolsUtils.jsm");
> 
> I believe you could also import makeInfallible from the JSM.
Done

> 
> @@ +55,5 @@
> > +      ", child process: " + DebuggerServer.isInChildProcess, filters);
> > +
> > +    this.owner = owner;
> > +
> > +    if (filters) {
> 
> It looks like filters is always defined, so we should need this `if`.
Done

> 
> @@ +177,5 @@
> > +      let winId = WindowUtils.getOuterId(this.window);
> > +      if (winId != msg.data.winId) {
> > +        return;
> > +      }
> > +    }
> 
> It would better to pass the `winID` to the parent process rather than
> filtering after we pipe the message back!
The filtering is actually done in the parent process already,
so, I changed the 'return' to 'throw new Error()'.

> 
> @@ +211,5 @@
> > +      return;
> > +    }
> > +
> > +    // better variable names for parsedMessages, parsedMessage and msg
> > +    // (probably a little piece of refactoring)
> 
> Is this a TODO comment?
> Could you do this refactoring/renaming and get rid of it?
Removed

> 
> @@ +315,5 @@
> > +
> > +  // Server Logs
> > +
> > +  parse: function(header, value) {
> > +    let result = decodeURIComponent(escape(atob(value)));
> 
> Do you really need all this? escape and decoreURIComponent after atob?
> I would have exception atob to be enough.
Hmm, I don't know, but this code is from Add-on SDK (sdk/base64 module),
so I tend to think that it's good to have it there...

> 
> Also if you have any (stable) link to refer to that documents this. 
> It would be great to mention it there.
Yep, good point, done:
https://craig.is/writing/chrome-logger/techspecs

> 
> @@ +335,5 @@
> > +      // new version without label
> > +      let newVersion = false;
> > +      if (data.columns.indexOf("label") === -1) {
> > +        newVersion = true;
> > +      }
> 
> You do not need this newVersion variable, you can merge the two `if`.
Fixed

> 
> @@ +339,5 @@
> > +      }
> > +
> > +      // if this is the old version do some converting
> > +      if (!newVersion) {
> > +        let showLabel = label && typeof label === "string";
> 
> It may be clearer if you move the `let label = ...` here.
Done

> 
> @@ +442,5 @@
> > +    // this.conn.send(packet);
> > +
> > +    // Log into the console using standard API now.
> > +    // xxxHonza: custom logging should be implemented
> > +    // by {@LoggerFront} object.
> 
> What is this LoggerFront? The current code looks good to me.
Removed (just forgotten comment)

> 
> @@ +443,5 @@
> > +
> > +    // Log into the console using standard API now.
> > +    // xxxHonza: custom logging should be implemented
> > +    // by {@LoggerFront} object.
> > +    let consoleEvent = clone(packet.message);
> 
> Why do you need to clone, it seems simple enough to be just passed as-is?
True, fixed. (it's clone in prepareConsoleMessageForRemote)

> 
> @@ +444,5 @@
> > +    // Log into the console using standard API now.
> > +    // xxxHonza: custom logging should be implemented
> > +    // by {@LoggerFront} object.
> > +    let consoleEvent = clone(packet.message);
> > +    consoleEvent.wrappedJSObject = consoleEvent;
> 
> I'm not sure you need this anymore if you pass it to the RDP protocol
Yep, removed.

> 
> @@ +452,5 @@
> > +
> > +    this.owner.onServerLogCall(consoleEvent);
> > +
> > +    //Services.obs.notifyObservers(consoleEvent,
> > +    //  "console-api-log-event", null);
> 
> Could you get rid of commented code?
Done

> 
> @@ +507,5 @@
> > +    if (!specifier) {
> > +      break;
> > +    }
> > +
> > +    specifiers.push(specifier);
> 
> This code looks unnecessary complex as it is splitted in two steps.
> I think it will be much easier if you combine both steps.
> i.e. you are building the concatenated string directly from this while loop.
> You may not inline everything in the while loop, having a sub function would
> help reading it.
> The important point is that you do not need the intermediate splitLogs and
> specifiers variables!
> 
> Also, I'm wondering... this feature is already implemented in the
> webconsole. Couldn't we just pass the printf-like string as-is and let the
> existing console code do this work?
> Or, if there is a reason that justify doing this right here and not later,
> couldn't we share the code?
Yes, the original idea was to share the code with webconsole, but the part
that is responsible for log arguments processing is done in C++
https://github.com/mozilla/gecko-dev/blob/b8ca505d1b792e56f0e5d1cc55a7bfb450c16cf8/dom/base/Console.cpp#L1475

It would be great if we should share the code and have it at the right
place/module (include simplifying the logic) and I think we should do
it as a follow up (it'll be useful for the new devtools tracing too).

> 
> @@ +559,5 @@
> > +          msg.styles.push(null);
> > +        }
> > +        msg.styles.push(argument);
> > +        // Go to next iteration directly.
> > +        return;
> 
> This comment is weird, is this copy pasted code?
> using return or break doesn't make any difference here.
Removed

> 
> @@ +571,5 @@
> > +    rebuiltLogArray.push(concatString);
> > +  }
> > +
> > +  // Prepend the items of the rebuilt log array of the first string
> > +  // to the message logs.
> 
> This comment isn't clear to me. Is this to support the cases where we pass
> more arguments to console.log than there is specifiers?
> Like: console.log("foo %s", "bar", "xxx"); ?
Yes, comment updated.


------------------------------------------------------------------------


(In reply to Panos Astithas [:past] from comment #22)
> Comment on attachment 8624265 [details] [diff] [review]
> bug1168872-5.patch
> 
> Review of attachment 8624265 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I have a bunch of comments and from an architectural point of view I would
> be happier if we could combine the server logger monitor with the existing
> network monitor. I understand that this may not be trivial and I'm not sure
> how familiar you have become with the network monitor, so I'm not going to
> insist if you don't feel like it, but it would be better both from a
> performance and a complexity point of view.
Agreed, I think we should create a follow up for this (and I am happy to work on it).

Btw. from the IRC:
<ochameau> past: I'm not sure pilling up another observer listener is such a big deal. but may be we can have one JS listener and quickly branch the various codes if features are enabled/disabled
<past> ochameau: sure, that's pretty much what I had in mind

And I also like the idea.

> 
> ::: browser/app/profile/firefox.js
> @@ +1595,5 @@
> >  pref("devtools.browserconsole.filter.windowlessworkers", true);
> > +pref("devtools.browserconsole.filter.servererror", true);
> > +pref("devtools.browserconsole.filter.serverwarn", true);
> > +pref("devtools.browserconsole.filter.serverinfo", true);
> > +pref("devtools.browserconsole.filter.serverlog", true);
> 
> These should be false by default. The Browser Console is used to debug the
> browser, not a server-side app.
Done

> 
> ::: browser/devtools/webconsole/console-output.js
> @@ +1297,5 @@
> >  {
> >    let options = {
> >      className: "cm-s-mozilla",
> >      timestamp: packet.timeStamp,
> > +    category: packet.category || "webdev",
> 
> I think it would be better to always send the category in both cases and
> still leave the "or" part here for backwards compatibility.
Done

> 
> @@ +1723,5 @@
> >    this._repeatID.consoleApiLevel = packet.level;
> >    this._arguments = packet.arguments;
> > +
> > +  // A message for console.table() method (passed in as the first argument)
> > +  // isn't supported. This should be fixed.
> 
> I don't understand this comment. This change modifies the way console.table
> works for web apps too.
Some server side libraries pass in a string as the first argument, which isn't
supported by the current impl of console.table(). But you are right, I moved the
check into a better place (ServerLoggingListener.sendMessage) to check only
"server" logs.

> 
> ::: browser/devtools/webconsole/webconsole.js
> @@ +34,5 @@
> >  loader.lazyImporter(this, "VariablesViewController", "resource:///modules/devtools/VariablesViewController.jsm");
> >  loader.lazyImporter(this, "PluralForm", "resource://gre/modules/PluralForm.jsm");
> >  loader.lazyImporter(this, "gDevTools", "resource:///modules/devtools/gDevTools.jsm");
> >  
> > +const { setTimeout, clearTimeout } = require("sdk/timers");
> 
> You can lazy-load this with loader.lazyRequireGetter().
Done

> 
> @@ +661,5 @@
> > +      try {
> > +        this.filterPrefs[pref] = Services.prefs.getBoolPref(
> > +          this._filterPrefsPrefix + pref);
> > +      } catch (err) {
> > +        Cu.reportError("Pref: " + pref + ", " + err);
> 
> What's the purpose of the try/catch block if you are adding the prefs in
> firefox.js anyway?
It just felt safer, but yeah, removed.

> 
> @@ +1016,5 @@
> > +      clearTimeout(this._updateListenersTimeout);
> > +    }
> > +
> > +    this._updateListenersTimeout = setTimeout(
> > +      this._onUpdateListeners, 200);
> 
> Why is the timeout needed? In particular, why is the reflow activity
> listener now updated after the timeout?
setFilterState() method is called several times (in a row) in order to update menuitems when the toolbar button-filter is clicked (see _setMenuState). This means that also _onUpdateListeners is called several times and several 'stop-listeners' packets sent to the backend. Introducing timeout represents a little optimization.

> 
> ::: browser/locales/en-US/chrome/browser/devtools/webConsole.dtd
> @@ +79,5 @@
> > +<!-- LOCALIZATION NOTE (btnServerLogging): This is used as the text of the
> > +  -  the toolbar. It shows or hides messages that the web developer inserted on
> > +  -  the page for debugging purposes, using calls on the HTTP server. -->
> > +<!ENTITY btnServerLogging.label       "Server">
> > +<!ENTITY btnServerLogging.tooltip     "Log messages received from HTTP server">
> 
> Nit: I think "Log messages received from a web server" is slightly better.
Fixed

> 
> ::: browser/themes/shared/devtools/webconsole.inc.css
> @@ +351,5 @@
> > +}
> > +
> > +.message[category=server][severity=info] > .icon::before {
> > +  background-position: -36px -36px;
> > +}
> 
> I think you can combine the last 3 rules with the ones for
> [category=console].
Nice catch, fixed

> 
> ::: toolkit/devtools/webconsole/server-logger-monitor.js
> @@ +55,5 @@
> > +
> > +  attach: makeInfallible(function({mm, prefix}) {
> > +    let size = this.messageManagers.size;
> > +
> > +    trace.log("ServerLoggerMonitor.attach; " + size, arguments);
> 
> I thought we decided to avoid string concatenation in logging calls in order
> to avoid the perf hit when logging is disabled, didn't we? There are many
> instances of this pattern in this file.
Yep, fixed (the code was written before)

> 
> @@ +109,5 @@
> > +        return this.onAttachChild(msg);
> > +      case "detachChild":
> > +        return this.onDetachChild(msg);
> > +      default:
> > +        Trace.error("Unknown method name: " + msg.data.method);
> 
> What is capital-case 'T' Trace.error? You only define trace.log above.
Fixed

> 
> You can also substitute |method| for |msg.data.method|, since you've already
> computed it above.
Done

> 
> ::: toolkit/devtools/webconsole/server-logger.js
> @@ +74,5 @@
> > +  },
> > +
> > +  /**
> > +   * The destroy is only called automatically by the framework (parent actor)
> > +   * if an actor is instantiated by a parent actor.
> 
> This listener object is not an actor, so the destroy() method is only
> executed manually in the owning actor, right?
Fixed

> 
> @@ +85,5 @@
> > +  },
> > +
> > +  /**
> > +   * Attach to this actor. Executed when the front (client) is attaching
> > +   * to this actor in order to receive server side logs.
> 
> Again, this is not an actor and AFAICS the only thing that calls attach() is
> the listener's initialize() method. Why not inline it in that case?
Fixed

> 
> @@ +108,5 @@
> > +
> > +  /**
> > +   * Detach from this actor. Executed when the front (client) detaches
> > +   * from this actor since it isn't interested in server side logs
> > +   * any more. So, let's remove the "http-on-examine-response" listener.
> 
> Again, since this is not an actor and detach() is only called from
> destroy(), better inline it.
Fixed

> 
> @@ +183,5 @@
> > +    switch (method) {
> > +      case "examineHeaders":
> > +        return this.onExamineHeaders(msg);
> > +      default:
> > +        Trace.error("Unknown method name: " + msg.data.method);
> 
> Capital 'T' Trace.error again.
Fixed

> 
> @@ +196,5 @@
> > +    trace.log("ServerLoggingListener.onExamineHeaders;", headers);
> > +
> > +    let parsedMessages = [];
> > +
> > +    headers.forEach(item => {
> 
> forEach is slower than for..of and traditional for loops. Since I expect
> this method to be called often, it would be nice to optimize it.
Done

> 
> @@ +288,5 @@
> > +      }
> > +    }
> > +
> > +    if (aChannel.loadInfo) {
> > +      if (aChannel.loadInfo.contentPolicyType == Ci.nsIContentPolicy.TYPE_BEACON) {
> 
> How can a navigator.sendBeacon() call be used to send server-side logging
> information? I don't think you need this check.
Removed

> 
> @@ +316,5 @@
> > +  // Server Logs
> > +
> > +  parse: function(header, value) {
> > +    let result = decodeURIComponent(escape(atob(value)));
> > +    let data = JSON.parse(result);
> 
> JSON.parse can throw and this is unsafe header data coming straight from the
> network, so better guard this with a try/catch block.
Done


Honza

Comment 24

[Jan Honza Odvarko [:Honza] (always need-info? me)]

The new patch (v6) pushed to try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=52dfce7cbb68

Looks good

(browser_webconsole_bug_653531_highlighter_console_helper.js is leaking, bug I guess it's unrelated)

Honza

Comment 25

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-7.patch

Patch rebased

Also tested (to make sure it works after Bug 1181100)

The main change is that 'atob'  is now imported using Cu.importGlobalProperties.

Honza

Comment 26

[Alexandre Poirot [:ochameau]]

Comment on attachment 8643026 [details] [diff] [review]
bug1168872-7.patch

Review of attachment 8643026 [details] [diff] [review]:
-----------------------------------------------------------------

I haven't had time to test it and finish the review, but here is a bunch of comments.

::: browser/devtools/moz.build
@@ +13,5 @@
>      'eyedropper',
>      'fontinspector',
>      'framework',
>      'inspector',
> +    'jsonview',

Leftover?

::: browser/devtools/webconsole/test/test-console-server-logging.sjs
@@ +29,5 @@
> +
> +function b64EncodeUnicode(str) {
> +  return btoa(encodeURIComponent(str).replace(/%([0-9A-F]{2})/g, function(match, p1) {
> +    return String.fromCharCode('0x' + p1);
> +  }));

Rather than copy pasting code from SDK, then from MDN, we should understand what's going on.
So as MDN says, this is about UTF8.
Then unescape(encodeURIComponent()) makes sense.
The MDN version looks less efficient than SDK one.

::: browser/devtools/webconsole/webconsole.js
@@ +703,5 @@
> +      prefs.forEach(pref => {
> +        if (this.filterPrefs[pref]) {
> +          startListener = true;
> +        }
> +      });

nit: for loop with break would prevent having to go though all items and call functions.
prefs.reduce wouldn't, but would prevent having modify startListener closure scope variable.
very-nit as this is such a small list.

::: toolkit/devtools/server/actors/webconsole.js
@@ +616,5 @@
> +              messageManager: messageManager
> +            };
> +
> +            this.serverLoggingListener =
> +              new ServerLoggingListener(filters, this);

Only pass window. You are not using appId, nor messageManager in ServerLoggingListener.
(You are using appId, but only in in-parent-process usecase, where we don't have apps!)
Also note that `window` will be null for browser (content) toolbox, you will have to handle that correctly in your module. It is equivalent of "log everything".

@@ +1472,5 @@
> +
> +    let packet = {
> +      from: this.actorID,
> +      type: "serverLogCall",
> +      message: this.prepareConsoleMessageForRemote(aMessage, useObjectGlobal),

Still don't get it. I don't see why we would ever set useObjectGlobal=true for server logs.
Given that log objects are crafted in chrome compartment/global, Cu.getGlobalObject(serverLogObj) is going to return server-logger.js's global.
I don't know exactly what does it changes, to change the global in makeDebuggeeValue.

And I still don't get why it would be any different between browser (content) toolbox and other toolboxes. Because isRootActor is only true for these two toolboxes. It's not used to distinguish child process.

Again, what happens if we always pass true?

::: toolkit/devtools/server/main.js
@@ +548,5 @@
> +    this.registerModule("devtools/server/actors/server-logger", {
> +      prefix: "serverLogger",
> +      constructor: "ServerLoggerActor",
> +      type: { tab: true }
> +    });

Do I miss part of this patch?
This file doesn't seem to exists?
There is toolkit/devtools/webconsole/server-logger.js but that isn't an actor.

::: toolkit/devtools/webconsole/server-logger-monitor.js
@@ +9,5 @@
> +const {Cu, Ci} = require("chrome");
> +const {DebuggerServer} = require("devtools/server/main");
> +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> +
> +loader.lazyImporter(this, "Services", "resource://gre/modules/Services.jsm");

const Services = require("Services");

@@ +26,5 @@
> + * used in e10s enabled browser only.
> + *
> + * Since child processes can't register HTTP event observer they use
> + * this module to do the observing in the parent process. This monitor
> + * is loaded through DebuggerServer.setupInParent() that is executed

DebuggerServer -> DebuggerServerConnection

@@ +27,5 @@
> + *
> + * Since child processes can't register HTTP event observer they use
> + * this module to do the observing in the parent process. This monitor
> + * is loaded through DebuggerServer.setupInParent() that is executed
> + * from within the child process. The execution is done by {@ServerLoggerActor}

There is no ServerLoggerActor. Did you meant ServerLoggingListener and/or WebConsoleActor?

@@ +77,5 @@
> +
> +    trace.log("ServerLoggerMonitor.detach; ", size);
> +
> +    // Unregister message listeners
> +    mm.removeMessageListener("debug:server-logger", this.onChildMessage);

`mm` is undefined?

@@ +172,5 @@
> +      return;
> +    }
> +
> +    // Chrome requests don't have a parent window.
> +    let win = requestFrame._contentWindow;

There should be a better way to filter this.
This is an xbl attribute. XBL is applied async and may race.
On top of that _contentWindow is set by some other jsm lazily.
Could you use NetworkHelper.getWindowForRequest() instead?

::: toolkit/devtools/webconsole/server-logger.js
@@ +11,5 @@
> +
> +const {DebuggerServer} = require("devtools/server/main");
> +const DevToolsUtils = require("devtools/toolkit/DevToolsUtils");
> +
> +// XXX until bug 937114 is fixed

bug 937114 is unrelated. This bug is about exposing atob/btoa to xpcshell, not sandboxes.
There is not plan to automatically expose atob/btoa to sandboxes.
But may be we should do it? or expose it more easily via require()?

@@ +14,5 @@
> +
> +// XXX until bug 937114 is fixed
> +Cu.importGlobalProperties(["atob"]);
> +
> +loader.lazyImporter(this, "Services", "resource://gre/modules/Services.jsm");

const Services = require("Services");

@@ +48,5 @@
> +   *        Object with the filters to use for network requests:
> +   *        - window (nsIDOMWindow): filter network requests by the associated
> +   *        window object.
> +   *        - appId (number): filter requests by the appId.
> +   *        - topFrame (nsIDOMElement): filter requests by their topFrameElement.

Here and elsewhere in this module, you can get rid of appId and topFrame, you are not really using them.

@@ +64,5 @@
> +    this.topFrame = filters.topFrame;
> +
> +    if (!this.window && !this.appId && !this.topFrame) {
> +      this._logEverything = true;
> +    }

At the end `_logEverything` is equivalent to `!window`

@@ +171,5 @@
> +
> +    // Filter out messages from different tabs. The messages are already
> +    // filtered by the HTTP observer (in the parent process in case of e10s),
> +    // and so the following error should never happen.
> +    if (this.window) {

I'm not sure we can hit the case where we are doing e10s thing and this.window is undefined, do we?

@@ +172,5 @@
> +    // Filter out messages from different tabs. The messages are already
> +    // filtered by the HTTP observer (in the parent process in case of e10s),
> +    // and so the following error should never happen.
> +    if (this.window) {
> +      let winId = getOuterId(this.window);

Try to compute the window id once instead of for each message.

@@ +267,5 @@
> +    if (!aChannel.loadInfo &&
> +        aChannel.loadInfo.loadingDocument === null &&
> +        aChannel.loadInfo.loadingPrincipal === Services.scriptSecurityManager.getSystemPrincipal()) {
> +      return false;
> +    }

Shouldn't we do the same thing in e10s usecase? Just wondering.

@@ +282,5 @@
> +          break;
> +        }
> +        win = win.parent;
> +      }
> +    }

I think you can get rid of the this.window check as you will always have one or log everything.

@@ +296,5 @@
> +      let appId = NetworkHelper.getAppIdForRequest(aChannel);
> +      if (appId && appId == this.appId) {
> +        return true;
> +      }
> +    }

You can get rid of topFrame and appId cases.

Comment 27

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-8.patch

(In reply to Alexandre Poirot [:ochameau] from comment #26)
> Comment on attachment 8643026 [details] [diff] [review]
> bug1168872-7.patch
> 
> Review of attachment 8643026 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I haven't had time to test it and finish the review, but here is a bunch of
> comments.
> 
> ::: browser/devtools/moz.build
> @@ +13,5 @@
> >      'eyedropper',
> >      'fontinspector',
> >      'framework',
> >      'inspector',
> > +    'jsonview',
> 
> Leftover?
Oops, yes, removed.

> 
> ::: browser/devtools/webconsole/test/test-console-server-logging.sjs
> @@ +29,5 @@
> > +
> > +function b64EncodeUnicode(str) {
> > +  return btoa(encodeURIComponent(str).replace(/%([0-9A-F]{2})/g, function(match, p1) {
> > +    return String.fromCharCode('0x' + p1);
> > +  }));
> 
> Rather than copy pasting code from SDK, then from MDN, we should understand
> what's going on.
> So as MDN says, this is about UTF8.
> Then unescape(encodeURIComponent()) makes sense.
> The MDN version looks less efficient than SDK one.
Fixed, using the following now: btoa(unescape(encodeURIComponent(str)));

> 
> ::: browser/devtools/webconsole/webconsole.js
> @@ +703,5 @@
> > +      prefs.forEach(pref => {
> > +        if (this.filterPrefs[pref]) {
> > +          startListener = true;
> > +        }
> > +      });
> 
> nit: for loop with break would prevent having to go though all items and
> call functions.
> prefs.reduce wouldn't, but would prevent having modify startListener closure
> scope variable.
> very-nit as this is such a small list.
Using for loop now + break now.

> 
> ::: toolkit/devtools/server/actors/webconsole.js
> @@ +616,5 @@
> > +              messageManager: messageManager
> > +            };
> > +
> > +            this.serverLoggingListener =
> > +              new ServerLoggingListener(filters, this);
> 
> Only pass window. You are not using appId, nor messageManager in
> ServerLoggingListener.
> (You are using appId, but only in in-parent-process usecase, where we don't
> have apps!)
> Also note that `window` will be null for browser (content) toolbox, you will
> have to handle that correctly in your module. It is equivalent of "log
> everything".
Done

> 
> @@ +1472,5 @@
> > +
> > +    let packet = {
> > +      from: this.actorID,
> > +      type: "serverLogCall",
> > +      message: this.prepareConsoleMessageForRemote(aMessage, useObjectGlobal),
> 
> Still don't get it. I don't see why we would ever set useObjectGlobal=true
> for server logs.
> Given that log objects are crafted in chrome compartment/global,
> Cu.getGlobalObject(serverLogObj) is going to return server-logger.js's
> global.
> I don't know exactly what does it changes, to change the global in
> makeDebuggeeValue.
> 
> And I still don't get why it would be any different between browser
> (content) toolbox and other toolboxes. Because isRootActor is only true for
> these two toolboxes. It's not used to distinguish child process.
> 
> Again, what happens if we always pass true?
This is only related to B2G. If the default global is used I am seeing the following exception:

Handler function threw an exception: TypeError: object in compartment marked as
invisible to Debugger
Stack: WCA_makeDebuggeeValue@resource://gre/modules/commonjs/toolkit/loader.js -
> resource://gre/modules/devtools/server/actors/webconsole.js:438:21

I don't understand why it only happens on B2G, but changing the global to |window| - the content window where the object (debuggee) lives solves the problem.

In any case I am seeing more problem when server-logging from B2G device:

1. Build b2g app
2. Load http://janodvarko.cz/test/serverlogging/test1.html
3. Run Firefox desktop, connect to the b2g app, open the Console panel (make sure to check server filters)
4. Generate some server-logs by clicking on the first group of buttons (on the test page)

Basic logging works (you can see server side logs in the Console panel), but when an object is passed there is an exception. Any tips why?

But, I tend to thing that we should solve b2g support in a follow up (if not easy to fix now).

> 
> ::: toolkit/devtools/server/main.js
> @@ +548,5 @@
> > +    this.registerModule("devtools/server/actors/server-logger", {
> > +      prefix: "serverLogger",
> > +      constructor: "ServerLoggerActor",
> > +      type: { tab: true }
> > +    });
> 
> Do I miss part of this patch?
> This file doesn't seem to exists?
> There is toolkit/devtools/webconsole/server-logger.js but that isn't an
> actor.
There is no new actor, removed.

> 
> ::: toolkit/devtools/webconsole/server-logger-monitor.js
> @@ +9,5 @@
> > +const {Cu, Ci} = require("chrome");
> > +const {DebuggerServer} = require("devtools/server/main");
> > +const {makeInfallible} = require("devtools/toolkit/DevToolsUtils");
> > +
> > +loader.lazyImporter(this, "Services", "resource://gre/modules/Services.jsm");
> 
> const Services = require("Services");
Done

> 
> @@ +26,5 @@
> > + * used in e10s enabled browser only.
> > + *
> > + * Since child processes can't register HTTP event observer they use
> > + * this module to do the observing in the parent process. This monitor
> > + * is loaded through DebuggerServer.setupInParent() that is executed
> 
> DebuggerServer -> DebuggerServerConnection
Done

> 
> @@ +27,5 @@
> > + *
> > + * Since child processes can't register HTTP event observer they use
> > + * this module to do the observing in the parent process. This monitor
> > + * is loaded through DebuggerServer.setupInParent() that is executed
> > + * from within the child process. The execution is done by {@ServerLoggerActor}
> 
> There is no ServerLoggerActor. Did you meant ServerLoggingListener and/or
> WebConsoleActor?
Yes, fixed

> 
> @@ +77,5 @@
> > +
> > +    trace.log("ServerLoggerMonitor.detach; ", size);
> > +
> > +    // Unregister message listeners
> > +    mm.removeMessageListener("debug:server-logger", this.onChildMessage);
> 
> `mm` is undefined?
Fixed

> 
> @@ +172,5 @@
> > +      return;
> > +    }
> > +
> > +    // Chrome requests don't have a parent window.
> > +    let win = requestFrame._contentWindow;
> 
> There should be a better way to filter this.
> This is an xbl attribute. XBL is applied async and may race.
> On top of that _contentWindow is set by some other jsm lazily.
> Could you use NetworkHelper.getWindowForRequest() instead?
NetworkHelper.getWindowForRequest() doesn't work in e10s since nsILoadContext.associatedWindow isn't available (and it also doesn't work in b2g, see the comment in getWindowForRequest)

Anyways, I changed that (to avoid using the '_contentWindow') to use only the requestFrame.


> 
> ::: toolkit/devtools/webconsole/server-logger.js
> @@ +11,5 @@
> > +
> > +const {DebuggerServer} = require("devtools/server/main");
> > +const DevToolsUtils = require("devtools/toolkit/DevToolsUtils");
> > +
> > +// XXX until bug 937114 is fixed
> 
> bug 937114 is unrelated. This bug is about exposing atob/btoa to xpcshell,
> not sandboxes.
> There is not plan to automatically expose atob/btoa to sandboxes.
> But may be we should do it? or expose it more easily via require()?
Yes, expose it via require would be the best I think. I can create a follow up if we have an agreement.


> 
> @@ +14,5 @@
> > +
> > +// XXX until bug 937114 is fixed
> > +Cu.importGlobalProperties(["atob"]);
> > +
> > +loader.lazyImporter(this, "Services", "resource://gre/modules/Services.jsm");
> 
> const Services = require("Services");
Done


> 
> @@ +48,5 @@
> > +   *        Object with the filters to use for network requests:
> > +   *        - window (nsIDOMWindow): filter network requests by the associated
> > +   *        window object.
> > +   *        - appId (number): filter requests by the appId.
> > +   *        - topFrame (nsIDOMElement): filter requests by their topFrameElement.
> 
> Here and elsewhere in this module, you can get rid of appId and topFrame,
> you are not really using them.
Done

> 
> @@ +64,5 @@
> > +    this.topFrame = filters.topFrame;
> > +
> > +    if (!this.window && !this.appId && !this.topFrame) {
> > +      this._logEverything = true;
> > +    }
> 
> At the end `_logEverything` is equivalent to `!window`
Done

> 
> @@ +171,5 @@
> > +
> > +    // Filter out messages from different tabs. The messages are already
> > +    // filtered by the HTTP observer (in the parent process in case of e10s),
> > +    // and so the following error should never happen.
> > +    if (this.window) {
> 
> I'm not sure we can hit the case where we are doing e10s thing and
> this.window is undefined, do we?
True, this shouldn't happen, removed.

> 
> @@ +172,5 @@
> > +    // Filter out messages from different tabs. The messages are already
> > +    // filtered by the HTTP observer (in the parent process in case of e10s),
> > +    // and so the following error should never happen.
> > +    if (this.window) {
> > +      let winId = getOuterId(this.window);
> 
> Try to compute the window id once instead of for each message.
Done

> 
> @@ +267,5 @@
> > +    if (!aChannel.loadInfo &&
> > +        aChannel.loadInfo.loadingDocument === null &&
> > +        aChannel.loadInfo.loadingPrincipal === Services.scriptSecurityManager.getSystemPrincipal()) {
> > +      return false;
> > +    }
> 
> Shouldn't we do the same thing in e10s usecase? Just wondering.
Yeah, make sense to me, done.

> 
> @@ +282,5 @@
> > +          break;
> > +        }
> > +        win = win.parent;
> > +      }
> > +    }
> 
> I think you can get rid of the this.window check as you will always have one
> or log everything.
Done

> 
> @@ +296,5 @@
> > +      let appId = NetworkHelper.getAppIdForRequest(aChannel);
> > +      if (appId && appId == this.appId) {
> > +        return true;
> > +      }
> > +    }
> 
> You can get rid of topFrame and appId cases.
Done

Thanks for the review!


Honza

Comment 28

[Alexandre Poirot [:ochameau]]

Comment on attachment 8644957 [details] [diff] [review]
bug1168872-8.patch

Review of attachment 8644957 [details] [diff] [review]:
-----------------------------------------------------------------

I've tested it now and it looks good.

I've let some other comments for followup, but I think we should figure out the debuggee issue before enabling this.

(In reply to Jan Honza Odvarko [:Honza] from comment #27)
> Created attachment 8644957 [details] [diff] [review]
> 
> > @@ +1472,5 @@
> > > +
> > > +    let packet = {
> > > +      from: this.actorID,
> > > +      type: "serverLogCall",
> > > +      message: this.prepareConsoleMessageForRemote(aMessage, useObjectGlobal),
> > 
> > Still don't get it. I don't see why we would ever set useObjectGlobal=true
> > for server logs.
> > Given that log objects are crafted in chrome compartment/global,
> > Cu.getGlobalObject(serverLogObj) is going to return server-logger.js's
> > global.
> > I don't know exactly what does it changes, to change the global in
> > makeDebuggeeValue.
> > 
> > And I still don't get why it would be any different between browser
> > (content) toolbox and other toolboxes. Because isRootActor is only true for
> > these two toolboxes. It's not used to distinguish child process.
> > 
> > Again, what happens if we always pass true?
> This is only related to B2G.

Ok, that makes a little bit more sense as at least we know there is some
specifics with JSM globals in b2g... it may have an impact somehow?

> If the default global is used I am seeing the
> following exception:
> 
> Handler function threw an exception: TypeError: object in compartment marked
> as
> invisible to Debugger
> Stack:
> WCA_makeDebuggeeValue@resource://gre/modules/commonjs/toolkit/loader.js -
> > resource://gre/modules/devtools/server/actors/webconsole.js:438:21

It makes also even more sense.
If I'm following your code correctly, we are creating the server message 
in ServerLoggingListener.parse, during JSON.parse.
We create *chrome* objects, living in chrome, in server-logger.js compartment.
server-logger being part of the debugger it is flagged as invisible to Debugger.
I would expect you to hit this everytime, not just on B2G.

> I don't understand why it only happens on B2G, but changing the global to
> |window| - the content window where the object (debuggee) lives solves the
> problem.

Given my comprehension of all this... I would never use getGlobalForObject.
I would always use this.window as debuggee, as I don't want to expose
any way to debug chrome objects. If we start exposing a debuggee from chrome
there is a chance we can somehow debug other chrome objects.

My previous comment wasn't crystal clear. So I would always set useObjectGlobal=false.
But then you won't be able to see the attributes of your objects as
the original object is a chrome one and your debuggee is content.

> But, I tend to thing that we should solve b2g support in a follow up (if not
> easy to fix now).

I fear this isn't just about b2g. we may easily leak some chrome privileges here.
But I think I got it now. You should try to create an object in content compartment,
using its JSON.parse. In ServerLoggingListener.parse, you would do:
  this.parentActor.window.JSON.parse(...)
And then you will always use useObjectGlobal=false, that to ensure
we always use content debuggee and not a chrome one.
(getGlobalForObject may still return server-logger global...)

::: browser/devtools/framework/gDevTools.jsm
@@ +28,5 @@
>  
>  const DefaultTools = require("definitions").defaultTools;
>  const EventEmitter = require("devtools/toolkit/event-emitter");
>  const Telemetry = require("devtools/shared/telemetry");
> +const JsonView = require("devtools/jsonview/main");

I imagine you had a conflict on my require refactoring.
I'm not seeing any 
  const JsonView = devtools.require("devtools/jsonview/main");
on master. Also it looks unrelated to this patch, right?

::: browser/devtools/webconsole/test/test-console-server-logging.sjs
@@ +13,5 @@
> +  var data = {
> +    "version": "4.1.0",
> +    "columns": ["log", "backtrace", "type"],
> +    "rows": [[
> +      ["values: %s %o %i %f","string",{"a":10,"___class_name":"Object"},123,1.12],

Could you also add a special UTF8 character (like ✓ - "\u2713") to test the unicode thing?

::: browser/devtools/webconsole/webconsole.js
@@ +696,5 @@
> +   */
> +  _updateServerLoggingListener:
> +    function WCF__updateServerLoggingListener(aCallback)
> +  {
> +    if (this.webConsoleClient) {

very-nit: I tend to prefer having a early return than putting the whole function code within a sub-if block.

@@ +699,5 @@
> +  {
> +    if (this.webConsoleClient) {
> +      let startListener = false;
> +      let prefs = ["servererror", "serverwarn", "serverinfo", "serverlog"];
> +      for (let i=0; i<prefs.length; i++) {

nit: I think we put spaces around operators:
i = 0 and i < prefs.length

::: toolkit/devtools/webconsole/server-logger-monitor.js
@@ +5,5 @@
> + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
> +
> +"use strict";
> +
> +const {Cu, Ci} = require("chrome");

nit: it doesn't look like you are using Cu.

@@ +171,5 @@
> +    // content.
> +    if (!httpChannel.loadInfo &&
> +        httpChannel.loadInfo.loadingDocument === null &&
> +        httpChannel.loadInfo.loadingPrincipal === Services.scriptSecurityManager.getSystemPrincipal()) {
> +      return false;

Use `return;` as this function doesn't have return value.

@@ +181,5 @@
> +    }
> +
> +    // Outer ID of the frame is the same as the content window
> +    // (but content window isn't easily accessible from the parent process).
> +    let winId = requestFrame.outerWindowID;

Unfortunately, this is also something from xbl:
  http://mxr.mozilla.org/mozilla-central/source/toolkit/content/widgets/remote-browser.xml?force=1#211
which is also set lazily.
I gave that some thoughts and filtering by window-id may be a dead end when done accross process.
May be we should filter by frame instead?
I think you will get the listening frame from `onChildMessage`, in `msg.target`.

(The nice thing if you do that is that everything will be much simplier.
 this.targets will just be a Set of Frames.
 onDetachChild will just do this.targets.delete(msg.target).
 No more actorId/winId to pass along/manager/filter/retrieve.)

I'm fine cleaning that up in a followup.

::: toolkit/devtools/webconsole/server-logger.js
@@ +424,5 @@
> +// Helpers
> +
> +function clone(obj = {}) {
> +  return JSON.parse(JSON.stringify(obj));
> +}

This method isn't used.

@@ +471,5 @@
> +    if (!specifier) {
> +      break;
> +    }
> +
> +    specifiers.push(specifier);

What about my comment 21 in simplifying the implementation of this by getting rid of splitLogs and specifiers variables that looks inefficient and useless.
Are you considering looking into sharing code with C++ console in followups? (That would be great and help Nick's plan!)

Comment 29

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-9.patch

(In reply to Alexandre Poirot [:ochameau] from comment #28)
> Comment on attachment 8644957 [details] [diff] [review]
> bug1168872-8.patch
> 
> Review of attachment 8644957 [details] [diff] [review]:
> -----------------------------------------------------------------
> My previous comment wasn't crystal clear. So I would always set
> useObjectGlobal=false.
Done

I have also used Cu.cloneInto(), so the result message data is
allocated in the right scope/compartment. Tested in e10s/none10s/b2g and works well for me.


> I imagine you had a conflict on my require refactoring.
> I'm not seeing any 
>   const JsonView = devtools.require("devtools/jsonview/main");
> on master. Also it looks unrelated to this patch, right?
Yes, removed.

> ::: browser/devtools/webconsole/test/test-console-server-logging.sjs
> @@ +13,5 @@
> > +  var data = {
> > +    "version": "4.1.0",
> > +    "columns": ["log", "backtrace", "type"],
> > +    "rows": [[
> > +      ["values: %s %o %i %f","string",{"a":10,"___class_name":"Object"},123,1.12],
> 
> Could you also add a special UTF8 character (like ✓ - "\u2713") to test the
> unicode thing?
Done

> 
> ::: browser/devtools/webconsole/webconsole.js
> @@ +696,5 @@
> > +   */
> > +  _updateServerLoggingListener:
> > +    function WCF__updateServerLoggingListener(aCallback)
> > +  {
> > +    if (this.webConsoleClient) {
> 
> very-nit: I tend to prefer having a early return than putting the whole
> function code within a sub-if block.
Done

> 
> @@ +699,5 @@
> > +  {
> > +    if (this.webConsoleClient) {
> > +      let startListener = false;
> > +      let prefs = ["servererror", "serverwarn", "serverinfo", "serverlog"];
> > +      for (let i=0; i<prefs.length; i++) {
> 
> nit: I think we put spaces around operators:
> i = 0 and i < prefs.length
Done

> 
> ::: toolkit/devtools/webconsole/server-logger-monitor.js
> @@ +5,5 @@
> > + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
> > +
> > +"use strict";
> > +
> > +const {Cu, Ci} = require("chrome");
> 
> nit: it doesn't look like you are using Cu.
Done

> 
> @@ +171,5 @@
> > +    // content.
> > +    if (!httpChannel.loadInfo &&
> > +        httpChannel.loadInfo.loadingDocument === null &&
> > +        httpChannel.loadInfo.loadingPrincipal === Services.scriptSecurityManager.getSystemPrincipal()) {
> > +      return false;
> 
> Use `return;` as this function doesn't have return value.
Done

> 
> @@ +181,5 @@
> > +    }
> > +
> > +    // Outer ID of the frame is the same as the content window
> > +    // (but content window isn't easily accessible from the parent process).
> > +    let winId = requestFrame.outerWindowID;
> 
> Unfortunately, this is also something from xbl:
>  
> http://mxr.mozilla.org/mozilla-central/source/toolkit/content/widgets/remote-
> browser.xml?force=1#211
> which is also set lazily.
> I gave that some thoughts and filtering by window-id may be a dead end when
> done accross process.
> May be we should filter by frame instead?
Nice, done

> 
> ::: toolkit/devtools/webconsole/server-logger.js
> @@ +424,5 @@
> > +// Helpers
> > +
> > +function clone(obj = {}) {
> > +  return JSON.parse(JSON.stringify(obj));
> > +}
> 
> This method isn't used.
Removed

> 
> @@ +471,5 @@
> > +    if (!specifier) {
> > +      break;
> > +    }
> > +
> > +    specifiers.push(specifier);
> 
> What about my comment 21 in simplifying the implementation of this by
> getting rid of splitLogs and specifiers variables that looks inefficient and
> useless.
Yep, let's do this in a follow up
https://bugzilla.mozilla.org/show_bug.cgi?id=1193197
(Florent could be interested in this, he originally wrote the code)


> Are you considering looking into sharing code with C++ console in followups?
> (That would be great and help Nick's plan!)
I am not sure what it means to "share code with C++ console", we werer rather blocked by the fact that part of the code is C++ and not JS. Anyways, I'll talk to Nick about it! (in the bug 1193197)

Thanks Alex for the review!

Honza

Comment 30

[Alexandre Poirot [:ochameau]]

Comment on attachment 8646232 [details] [diff] [review]
bug1168872-9.patch

Review of attachment 8646232 [details] [diff] [review]:
-----------------------------------------------------------------

(In reply to Jan Honza Odvarko [:Honza] from comment #29)
> Created attachment 8646232 [details] [diff] [review]
> bug1168872-9.patch
> 
> (In reply to Alexandre Poirot [:ochameau] from comment #28)
> > Comment on attachment 8644957 [details] [diff] [review]
>
> I have also used Cu.cloneInto(), so the result message data is
> allocated in the right scope/compartment. Tested in e10s/none10s/b2g and
> works well for me.

It works, but at the end you are going to allocate logs twice.
One time in the system compartment, during JSON.parse and another copy when we are doing Cu.cloneInto.
(And the webconsole/RDP code most likely does yet another copy :x)
Feel free to fix that as followup if that's easier, but please fix that.

> > Are you considering looking into sharing code with C++ console in followups?
> > (That would be great and help Nick's plan!)
> I am not sure what it means to "share code with C++ console", we werer
> rather blocked by the fact that part of the code is C++ and not JS. Anyways,
> I'll talk to Nick about it! (in the bug 1193197)

I don't know what are Nick's precise plan.
But Console is going to stay in C++, for sure!
There is no plan to convert it back to JS, there is a reason we rewrote it in C++ (performances).
What I have in mind is to make the C++ console instanciable and/or make it so that it accepts parameters.
In your cases, it would either allow to (be instanciable)|(accept parameters):
 - window-id (or anything to identify a window),
 - category to make any log appear as server log.

::: toolkit/devtools/server/actors/webconsole.js
@@ +1462,5 @@
> +    // All arguments within the message needs to be converted into
> +    // debuggees to properly send it to the client side.
> +    // Use the default target: this.window as the global object
> +    // (especially needed by B2G) since that's the correct scope
> +    // for data in the message. See also:

please update this comment, there is nothing specific to B2G anymore.
We just need to ensure makeDebuggeeValue use content debuggee and not server-loger.js's system one.

::: toolkit/devtools/webconsole/server-logger.js
@@ +130,5 @@
> +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> +    sendSyncMessage("debug:server-logger", {
> +      method: "attachChild",
> +      actorId: this.owner.actorID,
> +      winId: this.winId,

We don't need to pass actorId/winId anymore.

@@ +142,5 @@
> +    let { removeMessageListener, sendSyncMessage } = mm;
> +
> +    sendSyncMessage("debug:server-logger", {
> +      method: "detachChild",
> +      actorId: this.owner.actorID,

We don't need to pass actorId anymore.

@@ +174,5 @@
> +
> +    let parsedMessages = [];
> +
> +    for (let item of headers) {
> +      let header = item.header.toLowerCase();

This is already lowercased from both onExamineResponse.

@@ +177,5 @@
> +    for (let item of headers) {
> +      let header = item.header.toLowerCase();
> +      let value = item.value;
> +
> +      if (acceptableHeaders.indexOf(header) !== -1) {

You are already filtering by acceptableHeaders from both onExamineResponse.

@@ +358,5 @@
> +
> +  sendMessage: function(msg) {
> +    trace.log("ServerLoggingListener.sendMessage; message", msg);
> +
> +    let formatted = format(msg);

Is there a point in sending a message if format(msg) returns null?
Is that the case where the server does console.log() without any argument?

@@ +364,5 @@
> +
> +    if (formatted) {
> +      for (let log of formatted.logs) {
> +        if (typeof log == "object") {
> +          delete log.___class_name;

What's that delete?
Could you add a brief comment about this?
Also it looks like something that should be done in format(), not sendMessage()!

Comment 31

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-10.patch

(In reply to Alexandre Poirot [:ochameau] from comment #30)
> Comment on attachment 8646232 [details] [diff] [review]
> bug1168872-9.patch
> It works, but at the end you are going to allocate logs twice.
> One time in the system compartment, during JSON.parse and another copy when
> we are doing Cu.cloneInto.
> (And the webconsole/RDP code most likely does yet another copy :x)
> Feel free to fix that as followup if that's easier, but please fix that.
True bug 1193247

> I don't know what are Nick's precise plan.
> But Console is going to stay in C++, for sure!
> There is no plan to convert it back to JS, there is a reason we rewrote it
> in C++ (performances).
> What I have in mind is to make the C++ console instanciable and/or make it
> so that it accepts parameters.
> In your cases, it would either allow to (be instanciable)|(accept
> parameters):
>  - window-id (or anything to identify a window),
>  - category to make any log appear as server log.
I see. I think we can discuss further in bug 1193197 (I'll make sure Nick is aware of that).

> ::: toolkit/devtools/server/actors/webconsole.js
> @@ +1462,5 @@
> > +    // All arguments within the message needs to be converted into
> > +    // debuggees to properly send it to the client side.
> > +    // Use the default target: this.window as the global object
> > +    // (especially needed by B2G) since that's the correct scope
> > +    // for data in the message. See also:
> 
> please update this comment, there is nothing specific to B2G anymore.
> We just need to ensure makeDebuggeeValue use content debuggee and not
> server-loger.js's system one.
Updated 

> ::: toolkit/devtools/webconsole/server-logger.js
> @@ +130,5 @@
> > +    // Attach to the {@ServerLoggerMonitor} object to subscribe events.
> > +    sendSyncMessage("debug:server-logger", {
> > +      method: "attachChild",
> > +      actorId: this.owner.actorID,
> > +      winId: this.winId,
> 
> We don't need to pass actorId/winId anymore.
Removed

> 
> @@ +142,5 @@
> > +    let { removeMessageListener, sendSyncMessage } = mm;
> > +
> > +    sendSyncMessage("debug:server-logger", {
> > +      method: "detachChild",
> > +      actorId: this.owner.actorID,
> 
> We don't need to pass actorId anymore.
Removed

> 
> @@ +174,5 @@
> > +
> > +    let parsedMessages = [];
> > +
> > +    for (let item of headers) {
> > +      let header = item.header.toLowerCase();
> 
> This is already lowercased from both onExamineResponse.
Fixed

> 
> @@ +177,5 @@
> > +    for (let item of headers) {
> > +      let header = item.header.toLowerCase();
> > +      let value = item.value;
> > +
> > +      if (acceptableHeaders.indexOf(header) !== -1) {
> 
> You are already filtering by acceptableHeaders from both onExamineResponse.
Fixed 

> 
> @@ +358,5 @@
> > +
> > +  sendMessage: function(msg) {
> > +    trace.log("ServerLoggingListener.sendMessage; message", msg);
> > +
> > +    let formatted = format(msg);
> 
> Is there a point in sending a message if format(msg) returns null?
> Is that the case where the server does console.log() without any argument?
Yes, e.g. console.groupEnd()

> 
> @@ +364,5 @@
> > +
> > +    if (formatted) {
> > +      for (let log of formatted.logs) {
> > +        if (typeof log == "object") {
> > +          delete log.___class_name;
> 
> What's that delete?
> Could you add a brief comment about this?
Comment added (the property is for custom rendering of object classes, not supported).

> Also it looks like something that should be done in format(), not
> sendMessage()!
Moved

Thanks!

Honza

Comment 32

[Ryan VanderMeulen [:RyanVM]]

Please provide a more-recent Try link (the last one in this bug is nearly a month old and a lot can change in that much time).

Comment 33

[Jan Honza Odvarko [:Honza] (always need-info? me)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e62c3350b04c

Honza

Comment 34

[Jan Honza Odvarko [:Honza] (always need-info? me)]

There are some oranges related to:
browser/devtools/styleinspector/test/browser_styleinspector_tooltip-closes-on-new-selection.js

I believe it's unrelated, but Alex can you verify please?

Honza

Comment 35

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-11.patch

It turned out that the mem leak has been actually caused by the patch, so I am attaching new and fixed version.

- Detected memory leak fixed
- Test extended: browser_webconsole_bug_601667_filter_buttons.js

Try build:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cb30a12f675e

Honza

Comment 36

[Alexandre Poirot [:ochameau]]

Comment on attachment 8647552 [details] [diff] [review]
bug1168872-11.patch

Review of attachment 8647552 [details] [diff] [review]:
-----------------------------------------------------------------

That leaks was a good catch!

Comment 37

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: bug1168872-12.patch

(In reply to Alexandre Poirot [:ochameau] from comment #36)
> Comment on attachment 8647552 [details] [diff] [review]
> bug1168872-11.patch
Thanks for the review!

(attaching new rebased patch)

Honza

Comment 38

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Try build:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cb30a12f675e

(there is one intermittent, but I believe that it's unrelated)

Honza

Comment 39

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/28077c310d98

Comment 40

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/integration/fx-team/rev/28077c310d98

Comment 41

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/28077c310d98

Comment 42

[Liz Henry (:lizzard) (relman/hg->git project)]

Release Note Request (optional, but appreciated)
[Why is this notable]: Suggested by dev team
[Suggested wording]: Support server-side logging for Developer tools
[Links (documentation, blog post, etc)]: 

If you have improvements for the release note wording, please comment and needinfo me. Thanks!

Comment 43

[Will Bamberg [:wbamberg]]

Honza, do these docs capture it: https://developer.mozilla.org/en-US/docs/Tools/Web_Console/Console_messages#Server ?

Comment 44

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Looks good to me!

It would be great to have an example of server side code that creates a log (e.g. for NodeJS), but I don't know if this MDN page is the right place... (I can provide one if it helps)

Honza

Comment 45

[Will Bamberg [:wbamberg]]

(In reply to Jan Honza Odvarko [:Honza] from comment #44)
> Looks good to me!
> 
> It would be great to have an example of server side code that creates a log
> (e.g. for NodeJS), but I don't know if this MDN page is the right place...
> (I can provide one if it helps)

MDN is the right place, and it would help very much :).


> 
> Honza

Comment 46

[Krzysiek Grzembski]

It's quite new functionality so i don't know where to look for help. I found out that very long log entries (rest responses) are cut off after exact 200000 chars. This is limit for firefox console message, but is there any option to open original log message in new window/tab?

Comment 47

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Krzysiek Grzembski from comment #46)
> It's quite new functionality so i don't know where to look for help. I found
> out that very long log entries (rest responses) are cut off after exact
> 200000 chars. This is limit for firefox console message, but is there any
> option to open original log message in new window/tab?

Please file new bug report (this one is already closed) so, we can continue investigation/discussion about what's wrong.

Thanks!
Honza