1597767 - Protocol responses should not run while paused

Status: NEW

(DevTools :: Debugger, defect, P3)

Description

[Jason Laster [:jlast]]

It is possible for protocol responses to run while the debugger is paused. This creates some really weird situations when debugging where the state of the world changes while the debugger is paused:

Here's an example that I just ran into

1. Debugger pause packet is received with a frame form
2. debugger fetches frames from the server
3. debugger looks up the the frame front from the thread, which does not yet exist
4. debugger pauses
5. in the browser toolbox, i check to see if the frame front exists and notice it does. The reason for that is that the frames request resolved AFTER the debugger paused.

Here are some relevant logs:

0:16.95 GECKO(14164) >>> frames (request) server0.conn0.child1/workerTarget22/thread1
...
0:17.06 GECKO(14164) Pausing because server0.conn0.child1/workerTarget21/thread1 - server0.conn0.child1/workerTarget21/frame41 does not exists
...

 0:17.08 INFO Console message: [JavaScript Warning: "DebuggeeWouldRun: debuggee `resource://devtools/shared/base-loader.js:373' would run" {file: "resource://devtools/shared/builtin-modules.js" line: 221}]
 0:17.09 GECKO(14164) >>> frames (response) server0.conn0.child1/workerTarget21/thread1
 0:17.09 GECKO(14164) >> adding actor server0.conn0.child1/workerTarget21/frame41
 0:17.09 GECKO(14164)  manage@resource://devtools/shared/protocol/Pool.js:86:50
 0:17.09 GECKO(14164) manage@resource://devtools/shared/protocol/Front.js:88:11
 0:17.09 GECKO(14164) read@resource://devtools/shared/protocol/types.js:346:21
 0:17.09 GECKO(14164) types.addArrayType/read/<@resource://devtools/shared/protocol/types.js:214:33
 0:17.09 GECKO(14164) read@resource://devtools/shared/protocol/types.js:214:16
 0:17.09 GECKO(14164) read@resource://devtools/shared/protocol/types.js:256:39
 0:17.09 GECKO(14164) read@resource://devtools/shared/protocol/Response.js:102:22
 0:17.09 GECKO(14164) read@resource://devtools/shared/protocol/Response.js:73:24
 0:17.09 GECKO(14164) generateRequestMethods/</frontProto[name]/<@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:55:31
 0:17.09 GECKO(14164) enter@resource://devtools/server/actors/utils/event-loop.js:79:18
 0:17.09 GECKO(14164) _pushThreadPause@resource://devtools/server/actors/thread.js:250:15

Here is a patch with the logs:

diff --git a/devtools/client/debugger/src/client/firefox/commands.js b/devtools/client/debugger/src/client/firefox/commands.js
index 6e382675a124..ff2a9d75f283 100644
--- a/devtools/client/debugger/src/client/firefox/commands.js
+++ b/devtools/client/debugger/src/client/firefox/commands.js
@@ -345,6 +345,11 @@ async function getFrames(thread: string) {

 async function getFrameScopes(frame: Frame): Promise<*> {
   const frameFront = lookupThreadFront(frame.thread).get(frame.id);
+  if (!frameFront) {
+    dump(`Pausing because ${frame.thread} - ${frame.id} does not exists\n`);
+    debugger;
+  }
+
   return frameFront.getEnvironment();
 }

diff --git a/devtools/shared/protocol/Front/FrontClassWithSpec.js b/devtools/shared/protocol/Front/FrontClassWithSpec.js
index 27097fa98630..9a175c6bb154 100644
--- a/devtools/shared/protocol/Front/FrontClassWithSpec.js
+++ b/devtools/shared/protocol/Front/FrontClassWithSpec.js
@@ -33,6 +33,8 @@ var generateRequestMethods = function(actorSpec, frontProto) {
         );
       }

+      dump(`>>> ${name} (request) ${this.actorID}\n`)
+
       let packet;
       try {
         packet = spec.request.write(args, this);
@@ -48,6 +50,7 @@ var generateRequestMethods = function(actorSpec, frontProto) {

       return this.request(packet).then(response => {
         let ret;
+        dump(`>>> ${name} (response) ${this.actorID}\n`)
         try {
           ret = spec.response.read(response, this);
         } catch (ex) {
diff --git a/devtools/shared/protocol/Pool.js b/devtools/shared/protocol/Pool.js
index eac6d8eec9c7..bca9f0cc4917 100644
--- a/devtools/shared/protocol/Pool.js
+++ b/devtools/shared/protocol/Pool.js
@@ -81,6 +81,11 @@ class Pool extends EventEmitter {
         parent.unmanage(actor);
       }
     }
+
+    if (actor.actorID.includes('frame') && actor.actorID.includes("workerTarget")) {
+      dump(`>> adding actor ${actor.actorID}\n ${new Error('').stack.split('\\n').join("\n")}n`)
+    }
+
     this._poolMap.set(actor.actorID, actor);
   }

The interesting thing here is that the debugger allows server responses to run while the debugger is paused. This makes it very hard to understand the state of the world while debugging.

I think one reason this might happen is that we obviously want devtools to send requests while the debuggee is paused, we just don't want to do that while the debugger is paused.

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

The priority flag is not set for this bug.
:jlast, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 2

[Jason Laster [:jlast]]

I just talked to Jim offline. Here are some notes:

We go to great lengths in content to ensure that pausing stops the world. Things like promises, worker messages, setTimeout, network events are all suspended until the thread resumes. These guarantees fall under the umbrella of run-to-completion and ensure that the current event loop can run to completion before another one starts.

We do not have the same guarantees when debugging the devtools client from chrome (browser toolbox). It is impossible for us to stop the world when chrome pauses because that would mean stopping the browser. This means that today when the devtools client pauses there are many ways for the outside world to intervene (Services, CC, CI, transport, ...). The most frustrating example for me is the transport layer because I do not expect pending protocol requests to be resolved. This has happened atleast twice now. In this case, a request for thread frames was kicked off before the client paused and resolves after it paused. In another case, a request for a frame environment resolved after the client paused (https://phabricator.services.mozilla.com/D41057).

We could improve this by preventing the transport layer from dispatching responses while the client is paused. Of course, this does not prevent the outside world from intervening in other ways, but it would fix the most disruptive way.