Closed Bug 948061 Opened 8 years ago Closed 8 years ago

Debugger does not stop at breakpoint on page reload

Categories

(DevTools :: Debugger, defect, P2)

x86
macOS
defect

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: jrburke, Assigned: past)

Details

Attachments

(2 files, 1 obsolete file)

Tried with today's nightly, but see it in Aurora and latest Beta channel too:

1) Go to http://jrburke.com/projects/element-example/www/
2) Open debugger, select the www/app/main.js file.
3) Set a breakpoint on the line that has `console.log('FINISHED LOADING');`
4) Reload the page.

Actual results:

Debugger stops on the last line of the file, not at the breakpoint. The call stack just shows (global). Clicking on continue in the debugger also does not end up on the breakpoint.

Expected results:

Execution stops at the breakpoint line, and the stack shows more than just (global).

Notes:

The script is added dynamically to the page as the page loads, not part of the HTML source.
Attached patch It's a race folks (obsolete) — Splinter Review
So here is a patch that avoids this bug by adding a few dump() statements.
-__-
Assignee: nobody → past
Status: NEW → ASSIGNED
marking as assigned. P2, but could be convinced otherwise.
Priority: -- → P2
I am unclear how this group uses priority settings, but if it helps:

My concern is that seems to affect web apps that use an AMD loader, and so makes it hard to use Firefox for debugging those apps. An AMD loader is used for the FxOS email app, and the breakpoints are not so useful when running in `make DEBUG=1` in Nightly.
Priorities are something like this:

P1 - Everyone stop everything to help this get fixed.

P2 - Blocking another P2 or being actively worked on. *Must* be assigned.

P3 - Yeah we should definitely fix this when we get a chance.

P4 - Will accept patches.

P5 - Meta bugs.
Attached patch Add more loggingSplinter Review
This patch adds more logging around the newScript notifications and the subsequent breakpoint setting actions.
Attachment #8345324 - Attachment is obsolete: true
The problem is a race between the time loading main.js triggers Debugger.prototype.onNewScript and the time its inner scripts (the 2 functions) are parsed. If onNewScript gets called before inner scripts are parsed, it doesn't see them and attempts to set the breakpoint in the outer script, even though it doesn't contain any bytecode at the specified line (the breakpoint sliding feature we have for breakpoints in comments or empty lines).

With the attached patch applied, this is what I get on "good" reloads (the ones that pause at line 5):

>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/alameda.js:1-1357
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/app.js:1-15
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/app/main.js:1-7
>>>>>> findScripts.length: 3
>>> script: http://jrburke.com/projects/element-example/www/app/main.js:1-7
>>> script: http://jrburke.com/projects/element-example/www/app/main.js:1-6
>>> script: http://jrburke.com/projects/element-example/www/app/main.js:4-5
>>>>>> found script: http://jrburke.com/projects/element-example/www/app/main.js:4-5
>>>>>> with offsets: [, , , , , [0]]
>>>>>> setting bp@ offset: 0 line: 5
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/element.js:1-1814
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/basic-header.js:1
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/basic-header/main.js:1-44
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/template.js:1-90
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/sub-header.js:1-12

Now, if I keep reloading I will occasionally get this from a "bad" reload (the one that pauses at line 7):

>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/alameda.js:1-1357
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/app.js:1-15
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/app/main.js:1-7
>>>>>> findScripts.length: 1
>>> script: http://jrburke.com/projects/element-example/www/app/main.js:1-7
>>>>>> script not found, looking for innermost. findScripts.length: 1
>>>> script: http://jrburke.com/projects/element-example/www/app/main.js:1-7
>>>>> with offsets: [, [0], , , , , , [15]]
>>>>>> setting bp@ offset: 15 line: 7

[... breakpoint hits and I resume ...]

>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/element.js:1-1814
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/basic-header.js:1
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/basic-header/main.js:1-44
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/template.js:1-90
>>>>> onNewScript: http://jrburke.com/projects/element-example/www/lib/sub-header.js:1-12


This seems like a SpiderMonkey issue, as I seem to recall some bugs in the past around the onNewScript callback and JSScript creation. Jim will know for sure.

The only workaround I could think of was to set breakpoints in the next turn of the event loop, but that would almost certainly miss scripts that don't stick around long enough and are immediately executed and scavenged (e.g. scripts without function declarations that we often used to get bugs filed for).
Flags: needinfo?(jimb)
Let's absolutely avoid timing-based "fixes" like waiting for the next turn of the event loop.

I wonder whether it's really lazy scripts, though; D.p.findScripts calls js::Debugger::ScriptQuery::addCompartment, which calls JSCompartment::ensureDelazifyScriptsForDebugMode, which really ought to be creating any scripts that have been left uncompiled. Can you figure out why that call isn't causing the 1-6 and 4-5 scripts to be created?
Flags: needinfo?(jimb)
For whatever it's worth: here's a patch I've used in debugging lazy script issues in the past. It might help you figure out which scripts exist when, to help see why findScripts isn't seeing what it ought.
Thanks Jim, but now I can no longer reproduce the bug, even on a pristine fx-team tip (without any of the patches in this bug)! I tried both debug and opt builds, but no matter how many times I reload, it always stops at line 5.

I'm going to try a build on my 8yr-old Mac to see if it happens there, otherwise I'm going to assume this got somehow fixed.
Nope, I tested on 3 different machines (Mac & Linux) with 6 different build combinations. It seems that another change fixed this bug. James can you test with tomorrow's Nightly and report if it works for you too?
Flags: needinfo?(jrburke)
Woo! I just tried it with Nightly 29.0a1 (2014-01-24) on OS X, and it works now, so I'll close the bug, thanks for looking into it!
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Flags: needinfo?(jrburke)
Resolution: --- → WORKSFORME
Well, that was nice! :)
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.