1107656 - Error opening toolbox in e10s when browser toolbox is opened

Status: RESOLVED FIXED

(DevTools :: Framework, defect)

Description

[Brian Grinstead [:bgrins]]

STR:

1) Enable e10s
2) ./mach run --jsdebugger
3) Open the inspector panel

The toolbox opens, but the inspector never seems to initialize.  Here is the error I see:

console.error: 
  Error reading response to: getHighlighter
console.error: 
  Message: TypeError: v is undefined
  Stack:
    types.addActorType/type<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:273:21
RetVal<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:532:12
Response<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:700:12
frontProto/</proto[name]/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1312:17
resolve@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:40:40
then@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:20:43
resolve@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:72:11
Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1208:7
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14

*************************
A coding exception was thrown and uncaught in a Task.

Full message: TypeError: v is undefined
Full stack: types.addActorType/type<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:273:21
RetVal<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:532:12
Response<.read@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:700:12
frontProto/</proto[name]/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1312:17
resolve@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:40:40
then@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:20:43
resolve@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/deprecated-sync-thenables.js:72:11
Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1208:7
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14

*************************
console.error: 
  Message: Error: Unexpected packet conn0.child1/inspectorActor3, {"highligter":{"actor":"conn0.child1/highlighter24"},"from":"conn0.child1/inspectorActor3"}
  Stack:
    Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1191:17
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14

Handler function LocalDebuggerTransport instance's this.other.hooks.onPacket threw an exception: Error: Unexpected packet conn0.child1/inspectorActor3, {"highligter":{"actor":"conn0.child1/highlighter24"},"from":"conn0.child1/inspectorActor3"}
Stack: Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1191:17
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
Line: 1191, column: 16
console.error: 
  Message: Error: Unexpected packet conn0.child1/inspectorActor3, {"highligter":{"actor":"conn0.child1/highlighter24"},"from":"conn0.child1/inspectorActor3"}
  Stack:
    Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1191:17
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14

Handler function LocalDebuggerTransport instance's this.other.hooks.onPacket threw an exception: Error: Unexpected packet conn0.child1/inspectorActor3, {"highligter":{"actor":"conn0.child1/highlighter24"},"from":"conn0.child1/inspectorActor3"}
Stack: Front<.onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/server/protocol.js:1191:17
DebuggerClient.prototype.onPacket@resource://gre/modules/devtools/dbg-client.jsm:896:7
LocalDebuggerTransport.prototype.send/<@resource://gre/modules/devtools/dbg-client.jsm -> resource://gre/modules/devtools/transport/transport.js:545:11
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://gre/modules/devtools/DevToolsUtils.js:83:14
Line: 1191, column: 16

Comment 1

[Patrick Brosset <:pbro>]

While the request is "getHighlighter", the response is the one we normally get for "getWalker" requests. So something is confusing the server here.

DBG-SERVER: Received packet 16: {
  "type": "getHighlighter",
  "autohide": true,
  "to": "conn0.child1/inspectorActor3"
}
DBG-SERVER: Received packet 17: {
  "walker": {
    "actor": "conn0.child1/domwalker25",
    "root": {
      "actor": "conn0.child1/domnode24",
      "baseURI": "about:home",
      "nodeType": 9,
      "namespaceURI": null,
      "nodeName": "#document",
      "numChildren": 3,
      "isBeforePseudoElement": false,
      "isAfterPseudoElement": false,
      "isAnonymous": false,
      "isNativeAnonymous": false,
      "isXBLAnonymous": false,
      "isShadowAnonymous": false,
      "isDisplayed": true,
      "hasEventListeners": true
    }
  },
  "from": "conn0.child1/inspectorActor3"
}

Comment 2

[Patrick Brosset <:pbro>]

Wow, I have completely lost myself in DebuggerServer, DebuggerTransport, Connection, Socket, Target, and more connection manager wrappers and I'm confused about a lot of things. But I do suspect one thing:

When the normal toolbox is opened in an e10s tab and a debugger-server is started in the child content process, instead of seeing 1 connection only, I see 2.
More precisely, I see both DebuggerServer.connectPipe (which is for the local, non e10s connections only) and DebuggerServer.connectToParent (for e10s connections) being called.

I think that this extra, local-only, connection shouldn't be created, and that it causes problems later when the browser-toolbox is opened.

Comment 3

[Patrick Brosset <:pbro>]

So, when we create a local server in the chrome parent process, for communicating with the browser toolbox, we do this by creating a separate devtools loader, so that we can be sure to have a separate instance of the dbg-server:
http://mxr.mozilla.org/mozilla-central/source/browser/devtools/framework/ToolboxProcess.jsm#118

What that means though, is that the allocID used in DebuggerServerConnection is not going to be unique anymore across server instances.

And because both the normal Toolbox and the Browser Toolbox end up connecting to children processes using this as a prefix, we end up having the same prefix for totally different actors.

Comment 4

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

(In reply to Patrick Brosset [:pbrosset] [:patrick] from comment #3)
> So, when we create a local server in the chrome parent process, for
> communicating with the browser toolbox, we do this by creating a separate
> devtools loader, so that we can be sure to have a separate instance of the
> dbg-server:
> http://mxr.mozilla.org/mozilla-central/source/browser/devtools/framework/
> ToolboxProcess.jsm#118

The main reason a separate loader is used is to allow debugging DevTools actors.  Using the same loader as the in-tab server would allow all Browser Toolbox functionality except that part.  Anyway, just in case you are wondering why it's done this way.

> What that means though, is that the allocID used in DebuggerServerConnection
> is not going to be unique anymore across server instances.

Well, it never really was meant to be...  It gives a unique ID *for that server*.  But you can connect to many different servers.

If I first connect phone A with WebIDE, disconnect, and connect to phone B, it's likely that many of the same ID will be used: they are different servers.  However, I realize you are talking about one "thing" (desktop Firefox).  Still though, we should not assume that an ID makes any sense at all across different server instances.

> And because both the normal Toolbox and the Browser Toolbox end up
> connecting to children processes using this as a prefix, we end up having
> the same prefix for totally different actors.

Have you found a place where the client is assuming the ID is globally unique, instead of unique for a given server?

Comment 5

[Patrick Brosset <:pbro>]

(In reply to J. Ryan Stinnett [:jryans] from comment #4)
> (In reply to Patrick Brosset [:pbrosset] [:patrick] from comment #3)
> > So, when we create a local server in the chrome parent process, for
> > communicating with the browser toolbox, we do this by creating a separate
> > devtools loader, so that we can be sure to have a separate instance of the
> > dbg-server:
> > http://mxr.mozilla.org/mozilla-central/source/browser/devtools/framework/
> > ToolboxProcess.jsm#118
> 
> The main reason a separate loader is used is to allow debugging DevTools
> actors.  Using the same loader as the in-tab server would allow all Browser
> Toolbox functionality except that part.  Anyway, just in case you are
> wondering why it's done this way.
> 
> > What that means though, is that the allocID used in DebuggerServerConnection
> > is not going to be unique anymore across server instances.
> 
> Well, it never really was meant to be...  It gives a unique ID *for that
> server*.  But you can connect to many different servers.
> 
> If I first connect phone A with WebIDE, disconnect, and connect to phone B,
> it's likely that many of the same ID will be used: they are different
> servers.  However, I realize you are talking about one "thing" (desktop
> Firefox).  Still though, we should not assume that an ID makes any sense at
> all across different server instances.
Thanks for clarifying this.

> > And because both the normal Toolbox and the Browser Toolbox end up
> > connecting to children processes using this as a prefix, we end up having
> > the same prefix for totally different actors.
> 
> Have you found a place where the client is assuming the ID is globally
> unique, instead of unique for a given server?
I haven't found the place where that fails yet, but I know that if I change the code to make the allocID unique across servers, the bug goes away.
And it seems logical because if you open both a BT and a Toolbox, you end up having 2 sets of actors listening in the same tab child process, with the same prefix ID. And what I'm seeing at ChildDebuggerTransport level is that receiveMessage is called twice instead of once as a result.

Comment 6

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

(In reply to Patrick Brosset [:pbrosset] [:patrick] from comment #5)
> > > And because both the normal Toolbox and the Browser Toolbox end up
> > > connecting to children processes using this as a prefix, we end up having
> > > the same prefix for totally different actors.
> > 
> > Have you found a place where the client is assuming the ID is globally
> > unique, instead of unique for a given server?
> I haven't found the place where that fails yet, but I know that if I change
> the code to make the allocID unique across servers, the bug goes away.
> And it seems logical because if you open both a BT and a Toolbox, you end up
> having 2 sets of actors listening in the same tab child process, with the
> same prefix ID. And what I'm seeing at ChildDebuggerTransport level is that
> receiveMessage is called twice instead of once as a result.

Aha, yes, I see what you mean.  We call addMessageListener("debug:" + prefix + ":packet", ...), but this is a global namespace.  The event name would need to some kind of server ID as well.  The prefix is not enough.

Comment 7

[Patrick Brosset <:pbro>]

(In reply to J. Ryan Stinnett [:jryans] from comment #6)
> Aha, yes, I see what you mean.  We call addMessageListener("debug:" + prefix
> + ":packet", ...), but this is a global namespace.  The event name would
> need to some kind of server ID as well.  The prefix is not enough.
Exactly!
I think I may have a fix that only requires one preliminary child process round trip before generating the ID. I think it's better than having to track ID uniqueness at global level.
I'll try to post a patch as soon as I've figured out how to efficiently use hg bookmarks and review board (yay, a new workflow!)

Comment 8

[Patrick Brosset <:pbro>]

Attachment: MozReview Request: bz://1107656/pbrosset

/r/3979 - Bug 1107656 - Generate unique prefixes for e10s parent-child server connections

Pull down this commit:

hg pull review -r 2872c2adf7de14f03e13d07d7259ff72a47ad4bf

Comment 9

[Patrick Brosset <:pbro>]

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

Comment 10

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

https://reviewboard.mozilla.org/r/3979/#review3235

This doesn't seem quite right to me, mainly because the frame script can be re-run any number of times, so we have to account for this case.

Potentially you could resolve this by tracking the prefix outside of the frame script's IIFE, so it can be accessed by each execution.  Also, your prefix seems like a super-set (or "is more unique than") `childID`, so this could replace `childID` entirely.

Having said all this, Alex knows this code much better than I do, so I think he should do future reviews here.

::: toolkit/devtools/server/child.js
(Diff revision 1)
> +  let prefix = 1;

My understanding of frame scripts is that they are re-executed every time you load them.  So, I don't see how this can be right.

I would expect this to give you a prefix of 1 every time because each of the two parent process servers will run this frame script separately in the child.

::: toolkit/devtools/server/child.js
(Diff revision 1)
> +  addMessageListener("debug:get-next-prefix", function (msg) {
> +    sendAsyncMessage("debug:get-next-prefix", {prefix: prefix++});
> +  });

This also worries me because the frame script is re-executed, so you would bind multiple listeners for each execution and send mutiple prefix replies with different numbers after the first one.

Comment 11

[Patrick Brosset <:pbro>]

Oh you're right, the frame script is indeed re-executed everytime! I was assuming this would not be the case, and since the bug went away with this patch, I thought my assumption was correct. Turns out the same prefix 1 is returned every time.
I'll have to think about this more.

Comment 12

[Patrick Brosset <:pbro>]

I have another possible approach:

The problem only occurs when using the browser toolbox or the connect screen, because in both cases, we start a new debugger server in the same parent process where the debugger server for the usual toolbox is already running.
But we do so in a separate loader instance.

What about we have a unique ID at loader level? Whenever we'd create a new loader, this ID would increment, and we would feed it to the new debuggerserver we create in this loader.

I'll upload a patch in a second.

Comment 13

[Patrick Brosset <:pbro>]

Attachment: Generate unique prefixes for e10s parent-child server connections

Comment 14

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Comment on attachment 8570363 [details] [diff] [review]
Generate unique prefixes for e10s parent-child server connections

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

General idea seems sound.  I am out next week, have ochameau review.

::: browser/devtools/framework/ToolboxProcess.jsm
@@ +134,5 @@
>        this.debuggerServer.on("connectionchange", this.emit.bind(this));
>      }
>  
>      if (!this.debuggerServer.initialized) {
> +      this.debuggerServer.init(this.loader.loaderID);

Won't need this, see other comments.

::: toolkit/devtools/Loader.jsm
@@ +280,5 @@
>  
>    _provider: null,
>  
> +  get loaderID() {
> +    return ++gNextLoaderID;

You should save this on the instance so you don't a new answer every time for the same loader. :) Also probably just |ID| is ok?  |loaderID| feels a bit redundant.

::: toolkit/devtools/gcli/commands/listen.js
@@ +26,5 @@
>    let serverLoader = new DevToolsLoader();
>    serverLoader.invisibleToDebugger = true;
>    serverLoader.main("devtools/server/main");
>    let debuggerServer = serverLoader.DebuggerServer;
> +  debuggerServer.init(serverLoader.loaderID);

Won't need this, see other comments.

::: toolkit/devtools/server/main.js
@@ +173,2 @@
>     */
> +  init: function DS_init(serverPrefix) {

You don't need all these hoops of passing things through |init| and such.  We pass a |loader| global to any module loaded by |require|, so you can just do |loader.id| if you add the ID to the global[1].

[1]: https://dxr.mozilla.org/mozilla-central/source/toolkit/devtools/Loader.jsm#376

@@ +969,5 @@
>        connID = "conn" + this._nextConnID++ + '.';
>      }
> +
> +    if (this._serverPrefix) {
> +      connID = "server" + this._serverPrefix + "." + connID;

I *think* you only need to do this when there is no forwarding prefix, the |else| block above.

The forwarding prefix is passed when a child wants to set up forwarding and it looks today like "conn0.child2", so I think if you only change the |else|, it will naturally become "server0.conn0.child2".

Comment 15

[Patrick Brosset <:pbro>]

Thanks Ryan for these details, I had no idea we were exposing the loader in the globals. The code becomes *much* simpler with this. I'll ask Alex to review the next patch.

Comment 16

[Patrick Brosset <:pbro>]

Comment on attachment 8565880 [details]
MozReview Request: bz://1107656/pbrosset

/r/3979 - Bug 1107656 - Generate unique prefixes for e10s parent-child server connections

Pull down this commit:

hg pull review -r 2583d6f9d4bd12cfb336477b91f1be99857a2a85

Comment 17

[Alexandre Poirot [:ochameau]]

Comment on attachment 8565880 [details]
MozReview Request: bz://1107656/pbrosset

OMG! Why did anything worked with multiple server instances ?!
Looks good, would be great to have a comment in _onConnection.

Comment 18

[Patrick Brosset <:pbro>]

Added a comment as suggested by Alex.
Pushed to try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=47d269fa7c62

Comment 19

[Patrick Brosset <:pbro>]

Comment on attachment 8565880 [details]
MozReview Request: bz://1107656/pbrosset

https://reviewboard.mozilla.org/r/3977/#review3747

Ship It!

Comment 20

[Patrick Brosset <:pbro>]

(I'm a little confused about what mozreview does to bugzilla when re-uploading a previously R+'d patch, but anyway, in this last patch I just added the comment, and R+'d it myself).

Comment 21

[Ryan VanderMeulen [:RyanVM]]

I admittedly suck at MozReview, but I don't see the updated patch there. The last rev doesn't match what you pushed to Try.

Comment 22

[Patrick Brosset <:pbro>]

(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #21)
> I admittedly suck at MozReview, but I don't see the updated patch there. The
> last rev doesn't match what you pushed to Try.
Really? That's odd. I quickly checked the rev on Try and the diff at https://reviewboard.mozilla.org/r/3977/ and it looks like they are in sync to me.
Anyway, pushed to fx-team: https://hg.mozilla.org/integration/fx-team/rev/563608e9ff4d

Comment 23

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

https://hg.mozilla.org/mozilla-central/rev/563608e9ff4d

Comment 25

[Patrick Brosset <:pbro>]

Attachment: MozReview Request: Bug 1107656 - Generate unique prefixes for e10s parent-child server connections