Opening debugger hangs completely on large scripts

RESOLVED FIXED in Firefox 24

Status

defect
P2
normal
RESOLVED FIXED
7 years ago
11 months ago

People

(Reporter: luke, Unassigned)

Tracking

(Blocks 1 bug, {testcase})

unspecified
Firefox 24
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [games:p?][leave-open], )

Attachments

(1 attachment, 1 obsolete attachment)

Reporter

Description

7 years ago
STR:
 1. open http://syntensity.com/static/bb/client_5.html
 2. wait for it to load
 3. Tools -> Web Developer -> Debugger

This hangs the browser for at least the minute I waited.  It also hangs on some other large game scripts that I've tried.

Shark shows that 99% of the time is executing a regexp.  Opening it up in the debugger at one particular point, the JS stack is:

  RegExp exec
  exec (orion.js:12303)
  getNextMatch (orion.js:10865)
  parse (orion.js:10690)
  initialParse (orion.js:10584)
  onModelChanged (orion.js:10593)

On a more general note, I think we really want to support debugging these large scripts since we can expect more of them to pop up with games and, if we have the only debugger that doesn't die, we'll win the gamedevs.  Since it is easy to write code that blows up on these 1M line scripts, I think it is important to get some of these Emscripten games into automated testing: stepping, breaking, inspecting, logging, etc.
From the description this sounds like the known problem with Orion's syntax highlighting engine (e.g. bug 753330), but Mihai would know for sure. However, when I tried to reproduce this on fx-team tip, I got a crash:

Assertion failure: !!script->compartment()->debugMode() == !!originalDebugMode_, at /Users/past/src/fx-team/js/src/jsanalyze.cpp:2143

Full log here:

http://past.pastebin.mozilla.org/1647946

I should note that I waited long enough for the extra downloads to finish (sound files?), before starting the debugger. If I don't wait for the downloads (start the debugger right after the throbber stops spinning), I hit your case. Launching the debugger before the throbber stops, also leads to a crash.

Mihai, in this case unconditionally using the JavaScript syntax highlighter only improves the experience slightly, so it's not just the HTML highlighter that is to blame.
Reporter

Comment 2

7 years ago
(In reply to Panos Astithas [:past] from comment #1)
Heh, I did the same thing and filed bug 757400.
Assignee: nobody → vporof
Priority: -- → P2
Status: NEW → ASSIGNED
Whiteboard: games → [games:p1]
This is very much improved with the workaround from bug 751901.

Comment 4

7 years ago
I'm actively working on bug 757400.
I think this is also related to bug 748512.
Assignee: vporof → nobody
Status: ASSIGNED → NEW
can we get a retest on this?
Reporter

Comment 7

7 years ago
I retested on the url from comment 0.  The situation is better, but the browser hangs for a few seconds on any UI action like scrolling close the big long line that contains all code.

(Completely unrelated idea/question: are there any plans to do anything to assist debugging minified code?  It seems like inserting artificial line breaks (turning like 79 into line 79.1, 79.2, etc) would allow the developer to step through the code.)
(In reply to Luke Wagner [:luke] from comment #7)
> (Completely unrelated idea/question: are there any plans to do anything to
> assist debugging minified code?  It seems like inserting artificial line
> breaks (turning like 79 into line 79.1, 79.2, etc) would allow the developer
> to step through the code.)

In bug 762761 we intend to prettify minified code and generate a source map for debugging it.
Reporter

Comment 9

7 years ago
(In reply to Panos Astithas [:past] from comment #8)
Great!
Here is a very large unminified program,

http://www.syntensity.com/static/night11/high_minus.html

Opening the debugger is reasonable. Resizing the debugger area is a little sluggish but not too bad.

If I add a breakpoint at 136306 for example, then stepping through is often very slow - many seconds to move forward a single line. But sometimes it is snappy. The content of the lines doesn't seem related to the speed.
We could certainly benefit from some profiling on this. Thanks for the test case Alon (and for the retest, Luke).
Reporter

Comment 12

7 years ago
You're in luck, BenWa and Alex Crichton just landed JS profiling support for the SPS profiler:
  https://developer.mozilla.org/en/Performance/Profiling_with_the_Built-in_Profiler
This should show what JS is running.  (If you have any questions using it, ask BenWa on irc.)
Assignee: nobody → anton
Status: NEW → ASSIGNED
Dropping to games:p2 based on the assumption that the debugger is now fine on large scripts, and is just not fine on large *minified* scripts (e.g. single line scripts).  Is that correct?
Whiteboard: [games:p1] → [games:p2]
yeah, that would help performance immensely.

Note that the long lines problem comes down to gecko not dealing well with long horizontal spans of text in general. Those script files in View Source should behave just as badly.
(In reply to Rob Campbell [:rc] (:robcee) from comment #14)
> yeah, that would help performance immensely.

"not concatenating the generated code into a single multi-megabyte line of JS would help performance immensely" is what I meant there.
Yeah, this is most likely a dupe of 748512 and is not directly caused by how emscripten code looks.
Summary: opening debugger hangs completely on large (emscripten) scripts → Opening debugger hangs completely on large scripts
Is this still an issue?  There's a lot of referenced bugs here, but most unfixed (bug 751901, bug 748512).
Whiteboard: [games:p2] → [games:p?]
The issue was partially with our source editor and I don't remember it having any performance related updates so I'd say this is still an issue.
(In reply to Vladimir Vukicevic [:vlad] [:vladv] from comment #17)
> Is this still an issue?  There's a lot of referenced bugs here, but most
> unfixed (bug 751901, bug 748512).

Note that we landed a workaround in bug 751901, but left the bug open for a more comprehensive fix. Bug 748512 depends on an Orion update that is currently set aside in favor of bug 816756.
Depends on: 751901, 748512
Also, it would be useful to have an updated test case since the syntensity.com URL now 404s.
The BananaBread demo is currently up at

https://developer.mozilla.org/en-US/demos/detail/bananabread

You can get an even larger source file in the Epic Citadel demo,

http://www.unrealengine.com/html5/
Found a real world example where the debugger hangs forever and I had to force close Nightly. Not sure if this is related at all to source maps, but:

1. Go to http://lampwww.epfl.ch/~doeraene/presentations/scala-js-scaladays2013/#/8
2. Open debugger
3. Cry
It seems this *is* related to source maps. While testing on fx-team tip, disabling source maps via about:config makes my debugger happy again.

With source maps enabled, however, approximately a million and one errors like these get spewed in stdout:
DBG-SERVER: JSON.parse: unexpected character:
SourceMapConsumer@resource://gre/modules/devtools/SourceMap.jsm:67
TS__fetchSourceMap/promise<@resource://gre/modules/devtools/dbg-server.jsm -> resource://gre/modules/devtools/server/actors/script.js:2685
resolve@resource://gre/modules/commonjs/sdk/core/promise.js:120
then@resource://gre/modules/commonjs/sdk/core/promise.js:45
resolve@resource://gre/modules/commonjs/sdk/core/promise.js:187
resolve@resource://gre/modules/commonjs/sdk/core/promise.js:120
then@resource://gre/modules/commonjs/sdk/core/promise.js:45
resolve@resource://gre/modules/commonjs/sdk/core/promise.js:187
fetch/streamListener.onStopRequest@resource://gre/modules/devtools/dbg-server.jsm -> resource://gre/modules/devtools/server/actors/script.js:2918

Nick, is this a known thing?
Flags: needinfo?(nfitzgerald)
I think we should file a different bug for the JSON parsing issue.
(In reply to Panos Astithas [:past] from comment #24)
> I think we should file a different bug for the JSON parsing issue.

Yeah, totally.
Posted patch v1 (obsolete) — Splinter Review
The reasons for the JSON.parse error are because we were getting a 404 on fetching the source map, but for whatever reason the resulting 404 html page was still being resolved in |fetch|. That isn't the real issue here though. The problem was that we are doing so much repeated work because we aren't only looking at top level scripts when we are trying to infer scripts -> sources. This is why the same message was showing up thousands and thousands of time instead of just once.

https://tbpl.mozilla.org/?tree=Try&rev=614076a69141

* s/_discoverScriptsAndSources/_discoverSources/ more accurately describes what it is doing since we don't have "scripts" packets anymore and this is only used to infer the existence of sources by the |onSources| handler.

* Only consider top level scripts in |discoverSources| since they are the only ones that can be sources

* Only create sources if the script is top level in |_addScript| and |_addScriptSync|
Attachment #763890 - Flags: review?(past)
Flags: needinfo?(nfitzgerald)
With this patch, the scala page goes from perma beach ball to near instant.
Comment on attachment 763890 [details] [diff] [review]
v1

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

This is a very good idea, but we need to be careful. Using this patch on G+ I get around half the sources I see in a Nightly. Not sure why, but this is scary and we need to figure it out. Also, don't forget that we take the opportunity to set stored breakpoints in onSources, so we need to make sure that we can still do that.

::: toolkit/devtools/server/actors/script.js
@@ +750,5 @@
> +
> +    let scripts = this.dbg.findScripts()
> +      // We only want to get top level scripts, because they are the only ones
> +      // that will introduce new sources.
> +      .filter(s => s.staticLevel === 0);

Filtering here means that _addScript[Sync] won't get a chance to set breakpoints on inner scripts later on.

@@ +1325,5 @@
>  
> +    // Only make sources for top level scripts.
> +    if (aScript.staticLevel === 0) {
> +      this.sources.source(aScript.url);
> +    }

Filtering here makes a ton of sense though!

@@ +2644,5 @@
>     */
>    sourcesForScript: function TS_sourcesForScript(aScript) {
> +    if (aScript.staticLevel !== 0) {
> +      return resolve([]);
> +    }

Isn't this redundant, since you've already checked before calling this method?
Attachment #763890 - Flags: review?(past) → review-
(In reply to Panos Astithas [:past] from comment #28)
> Comment on attachment 763890 [details] [diff] [review]
> v1
> 
> Review of attachment 763890 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> This is a very good idea, but we need to be careful. Using this patch on G+
> I get around half the sources I see in a Nightly. Not sure why, but this is
> scary and we need to figure it out.

Agreed, this doesn't make any sense whatsoever. Eval'd scripts have a higher staticLevel property, but we don't properly support them yet.

Jim, do you have any idea why we might be getting less sources if we only consider |D.Script|s with |staticLeve === 0|?

> Also, don't forget that we take the
> opportunity to set stored breakpoints in onSources, so we need to make sure
> that we can still do that.

It is completely bass ackwards that the behavior of the thread (stopping at pre-existing breakpoints) depends on a "sources" request being sent. Originally, I thought that this was handled by calling |_addScript| in |onNewScript|, but I just realized that |onNewScript| only gets passed top level scripts.

Instead of relying on the "sources" packet being sent, I think we should recurse through all the child scripts in |onNewScript| calling |_addScript| and restoring the breakpoints along the way. This way we can put off the work of restoring breakpoints until when absolutely needed and can still make |onSources| fast because it won't need to walk the whole script tree.

Or maybe we can restore breakpoints in |onEnterFrame|? Anything so that we don't have to walk the entire script tree all at once, because that is really killing us. As long as we have to do that, we won't be performant.

One other thing I noticed, is that our restoring breakpoint logic goes from the the last line of the script backwards over each line, but instead of stopping at the script's start line, keeps going to line 0. We are potentially doing a ton of unnecessary empty loops because of that.

Also, I also was wondering about the restoring breakpoints thing, before I mistakenly thought that onNewScript would handle that, and tried having only the sources filter for |staticLevel === 0| but still have the breakpoints restored on every script. It was faster than before, but nothing incredible. Perma beach ball became minute or two beach ball on the scala site.

> 
> ::: toolkit/devtools/server/actors/script.js
> @@ +750,5 @@
> > +
> > +    let scripts = this.dbg.findScripts()
> > +      // We only want to get top level scripts, because they are the only ones
> > +      // that will introduce new sources.
> > +      .filter(s => s.staticLevel === 0);
> 
> Filtering here means that _addScript[Sync] won't get a chance to set
> breakpoints on inner scripts later on.

We should restore breakpoints in |onNewScript| as mentioned above.

> 
> @@ +1325,5 @@
> >  
> > +    // Only make sources for top level scripts.
> > +    if (aScript.staticLevel === 0) {
> > +      this.sources.source(aScript.url);
> > +    }
> 
> Filtering here makes a ton of sense though!
> 
> @@ +2644,5 @@
> >     */
> >    sourcesForScript: function TS_sourcesForScript(aScript) {
> > +    if (aScript.staticLevel !== 0) {
> > +      return resolve([]);
> > +    }
> 
> Isn't this redundant, since you've already checked before calling this
> method?

Couldn't it be called elsewhere as well? I don't think we should assume that it is only called from one place, |ThreadSources| should be able to stand on its own without relying on callees. Alternatively, maybe we just need to decide that it is |ThreadSource|'s responsibility to do the filtering, or the callee's. Opinion?
Hey Jim, sorry forgot to needinfo? you in the above comment. Can you reply to this:


> Jim, do you have any idea why we might be getting less sources if we only
> consider |D.Script|s with |staticLeve === 0|?
Flags: needinfo?(jimb)
Posted patch v2Splinter Review
https://tbpl.mozilla.org/?tree=Try&rev=e746255b4195

* Decoupled sources from breakpoint restoration, as discussed on irc

* Moved breakpoint restoration to |onAttach|, as discussed on irc

* Don't use staticLevel to filter scripts before inferring sources from them, instead just ensure that we only have one script per script url. This fixes the issue where sources weren't showing up anymore (because the top level script would be gc'd by the time we looked for it).
Attachment #763890 - Attachment is obsolete: true
Attachment #764313 - Flags: review?(past)
Flags: needinfo?(jimb)
Comment on attachment 764313 [details] [diff] [review]
v2

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

::: toolkit/devtools/server/actors/script.js
@@ +217,5 @@
>          return { error: "notAttached" };
>        }
>        packet.why = { type: "attached" };
>  
> +      this._restoreBreakpoints();

It's late and I'm going to look into this more tomorrow, but I think this should be done after we spawn the nested event loop, in order to avoid delaying the pause.

@@ +1307,5 @@
>     * @param aScript Debugger.Script
>     *        The source script that will be stored.
>     * @returns true, if the script was added; false otherwise.
>     */
> +  _addScript: function TA__addScriptSync(aScript) {

Ditch the (wrong) function name.
Comment on attachment 764313 [details] [diff] [review]
v2

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

(In reply to Panos Astithas [:past] from comment #32)
> It's late and I'm going to look into this more tomorrow, but I think this
> should be done after we spawn the nested event loop, in order to avoid
> delaying the pause.

On second thought, this should be fine as it is, since SpiderMonkey isn't interruptible.
Attachment #764313 - Flags: review?(past) → review+
https://hg.mozilla.org/integration/fx-team/rev/feeeb2cb6a46
Whiteboard: [games:p?] → [games:p?][fixed-in-fx-team][leave-open]
Assignee: anton → nobody
https://hg.mozilla.org/mozilla-central/rev/feeeb2cb6a46
Flags: in-testsuite+
Whiteboard: [games:p?][fixed-in-fx-team][leave-open] → [games:p?][leave-open]
Duplicate of this bug: 922736
Is there any reason why this is still [leave-open]?
I'll take that silence as a "no".

Anyone's guess which target milestone this was in?
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED
Looking at the release calendar, I'll say Firefox 24:

https://wiki.mozilla.org/RapidRelease/Calendar
Target Milestone: --- → Firefox 24

Updated

11 months ago
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.