[e10s] console fails to evaluate script, and stepping is broken in the debugger after setting a breakpoint that gets hit on page load and reloading 2 times

RESOLVED DUPLICATE of bug 1299602

Status

defect
P1
normal
RESOLVED DUPLICATE of bug 1299602
4 years ago
Last year

People

(Reporter: bgrins, Unassigned)

Tracking

(Depends on 1 bug, Blocks 1 bug)

46 Branch
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(e10s+)

Details

(Whiteboard: [btpp-fix-now])

+++ This bug was initially created as a clone of Bug #1240881 +++

STR (See https://bugzilla.mozilla.org/show_bug.cgi?id=1240881#c7)

Enable e10s
Open https://bugzilla.mozilla.org/attachment.cgi?id=8712417
Open debugger and set breakpoint on line 3 of the html page
Reload page twice
Evaluate 1+1 in console

Expected:
console outputs 2

Actual:
console doesn't output anything
Broke this out into another bug so that I can land the fix in Bug 1240881, which fixes a perma fail on the console until the tab is closed when following the same STR.
Whiteboard: [btpp-fix-now]
Summary: [e10s] console hangs when debugging and reloading a few times → [e10s] console fails to evaluate script when debugging and reloading a few times
tracking-e10s: --- → +
I'm seeing this error show up in the page's console after the second reload.  (I've set javascript.options.throw_on_debuggee_would_run and javascript.options.dump_stack_on_debuggee_would_run to true):

DebuggeeWouldRun: debuggee `https://bug1240881.bmoattachments.org/attachment.cgi?id=8712417:2' would run script.js:348:5

Which points to this call to enterNestedEventLoop: https://dxr.mozilla.org/mozilla-central/source/devtools/server/actors/script.js#348.

James, can you help me sort this out?  I don't know in what case this would be happening.  Feel free to ping me tomorrow and we can chat further
Flags: needinfo?(jlong)
Talked with shu and sounds like the Debuggee Would Run warning may or may not be related to this issue (although it's a coincidence that it happens during the second reload at the same time console evaluation stops working).  The actual error has to do with dead frame actors.  The console sends this packet to the backend:

to	"server1.conn4.child1/consoleActor2"
type	"evaluateJSAsync"
text	"1+1"
frameActor	"server1.conn4.child1/37"
selectedNodeActor	""

Which returns:

unknownError
error occurred while processing 'evaluateJSAsync: Error: Debugger.Frame is not live Stack: WCA_evalWithDebugger@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webconsole.js:1248:11 WCA_onEvaluateJS@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webconsole.js:872:20 WCA_onEvaluateJSAsync@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webconsole.js:842:20 DSC_onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/main.js:1643:15 ChildDebuggerTransport.prototype.receiveMessage@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/transport/transport.js:742:5 EventLoop.prototype.enter@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:348:5 ThreadActor.prototype._pushThreadPause@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:542:5 ThreadActor.prototype._pauseAndRespond@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:752:7 BreakpointActor<.hit@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/breakpoint.js:173:12 @https://bug1240881.bmoattachments.org/attachment.cgi?id=8712417:3:5 Line: 1248, column: 11
I'm also seeing this error on the second reload:

"Handler function DebuggerProgressListener.prototype.onStateChange threw an exception: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIRequest.suspend]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webbrowser.js :: TabActor.prototype._willNavigate :: line 1791"  data: no]
Stack: TabActor.prototype._willNavigate@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webbrowser.js:1791:7
DebuggerProgressListener.prototype.onStateChange<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webbrowser.js:2325:7
exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
TabActor.prototype.onReload/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/webbrowser.js:1422:7
exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
EventLoop.prototype.enter@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:348:5
ThreadActor.prototype._pushThreadPause@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:542:5
ThreadActor.prototype._pauseAndRespond@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:752:7
BreakpointActor<.hit@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/breakpoint.js:173:12
@https://bug1240881.bmoattachments.org/attachment.cgi?id=8712417:3:5
Line: 1791, column: 0"
Found Bug 1093535 about this nsIRequest.suspend error although that's referencing debugger tests and we are seeing it in the normal toolbox here.  This is the exact code that is calling suspend(): https://dxr.mozilla.org/mozilla-central/source/devtools/server/actors/webbrowser.js#1790.  If I try/catch that call then I can continue evaluating in the console but the breakpoint isn't hit on the next reload.  

Eddy, does this look like something that could be causing the dead frame error?  Here's what I'm thinking happens:

* It's throwing on that line and then it's not calling a lot of debugger stuff like threadActor.unsafeSynchronize, threadActor.disableAllBreakpoints and then finally sending "tabNavigated"
* The webconsole is fetching cached frames from the debugger via DebuggerController.StackFrames.activeThread.cachedFrames: https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/hudservice.js#534
* cachedFrames is cleared via _clearFrames: https://dxr.mozilla.org/mozilla-central/source/devtools/shared/client/main.js#2223
* _clearFrames is called _onThreadState, which is called when tabNavigated happens: https://dxr.mozilla.org/mozilla-central/source/devtools/shared/client/main.js#1007

So, by throwing on the call to nsIRequest.suspend the cached frames get all out of whack and the console happily passes along a dead frame to evalWithDebugger.  This is breaking the webconsole, but I just checked and it's also breaking stepping in the debugger!  I also imagine all sorts of things are broken in the tools due to tabNavigated not getting called properly.  Can you please help figure out what's going on?
Flags: needinfo?(ejpbruel)
See Also: → 1093535
Summary: [e10s] console fails to evaluate script when debugging and reloading a few times → [e10s] console fails to evaluate script, and stepping is broken in the debugger after setting a breakpoint that gets hit on page load and reloading 2 times
Your analysis of the problem makes sense to me at first glance.

The main question then becomes: why does nsIRequest.suspend fail when e10s is enabled? Which is what bug 1093535 is about.

I briefly looked at bug 1093535 last year, but never figured out what caused it. Let's see if we can either figure it out, or find someone to look into it.
Flags: needinfo?(ejpbruel)
(In reply to Brian Grinstead [:bgrins] from comment #5)
> Found Bug 1093535 about this nsIRequest.suspend error although that's
> referencing debugger tests and we are seeing it in the normal toolbox here. 
> This is the exact code that is calling suspend():
> https://dxr.mozilla.org/mozilla-central/source/devtools/server/actors/
> webbrowser.js#1790.  If I try/catch that call then I can continue evaluating
> in the console but the breakpoint isn't hit on the next reload.  
> 


Yikes, I didn't know we used `unsafeSynchronize` there! Those lines of code seem brittle. What is it trying to achieve? Why do we need to suspend the request? Why not send the resume packet and continue executing the rest of the code on response?
Flags: needinfo?(jlong)
Setting ni? for the questions in Comment 7
Flags: needinfo?(ejpbruel)
There's no way we should need `unsafeSynchronize` there. All it needs to do is resume the debugger which should be done synchronously as this is backend code. I'm still not sure about the `request.suspend()`
(In reply to James Long (:jlongster) from comment #9)
> There's no way we should need `unsafeSynchronize` there. All it needs to do
> is resume the debugger which should be done synchronously as this is backend
> code. I'm still not sure about the `request.suspend()`

(In reply to Brian Grinstead [:bgrins] from comment #8)
> Setting ni? for the questions in Comment 7

That code makes no sense to me either. I think the reasoning here was that since onResume *could* return a promise, we have to wait for that promise to complete before the resume can be considered complete.

However, onResume only behaves asynchronously when you pass it a resume limit, which we don't do here, so it should be safe to ignore the promise and remove the call to unsafeSynchronise here.
Flags: needinfo?(ejpbruel)
Interesting, this STR seems to be working for me in a Nightly 51 build.  James / Eddy, can you confirm that it's working?  Also, any idea what might have changed here to fix it?
Flags: needinfo?(jlong)
Flags: needinfo?(ejpbruel)
Oh, it's definitely bug 1299602. I think that `request.suspend` got removed. Does everything here work now?
Flags: needinfo?(jlong)
The STR here are now working for me: https://bugzilla.mozilla.org/show_bug.cgi?id=1254613#c0.  If it's working also for you then feel free to dupe this to Bug 1299602
Works for me too!
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1299602
(In reply to Brian Grinstead [:bgrins] from comment #11)
> Interesting, this STR seems to be working for me in a Nightly 51 build. 
> James / Eddy, can you confirm that it's working?  Also, any idea what might
> have changed here to fix it?

Seems to be working for me to. I have no idea what changed to fix this.
Flags: needinfo?(ejpbruel)
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.