930141 - Pretty printing takes way longer than other devtools

Status: VERIFIED FIXED

(DevTools :: Debugger, defect)

Description

[Anthony Ricaud (:rik)]

On http://jquery.com, pretty printing jquery.js takes several seconds in Firefox. In other tools, it's less than 500ms, feels instant.

(This might not be the best test case given that this file contains source maps but I've seen the same behaviour on basically every script)

Comment 1

[Jeff Griffiths (:canuckistani) (:⚡︎)]

This is definitely the main problem we see with it currently.

Comment 2

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

This doesn't need to block bug 913665.

I'm working on replacing parsing + escodegen with an approach that pretty much just counts open and close curlies. Will commandeer this bug for that.

Comment 3

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Depends on bug 924466 because I need a lexer. Using acorn's lexer, since that is what benvie will integrate.

Comment 4

[Victor Porof [:vporof][:vp]]

(In reply to Nick Fitzgerald [:fitzgen] from comment #3)
> Depends on bug 924466 because I need a lexer. Using acorn's lexer, since
> that is what benvie will integrate.

Yay!

Comment 5

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

I pushed the new pretty printing library here: https://github.com/mozilla/pretty-fast

Benvie reviewed it (couldn't do a PR because it was the initial commit) here: https://github.com/mozilla/pretty-fast/commit/2c3096a10b752219940891fe14597982e9212866#commitcomment-4483998

Am fixing up based on his feedback now. Will start integrating with out tools soon.

Comment 6

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: WIP pretty-fast.patch

* Added pretty-fast to the tree

* Integrated tests

* Moved acorn/acorn to acorn and acorn/acorn_loose to acorn_loose, so that require calls can be the same in node and in firefox

* Integrated with debugger (soooo  much faster, so much nicer, has comments)

TODO:

* remove escodegen

* integrate with scratchpad

Aside: will probably want to uplift this to aurora.

Comment 7

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: pretty-fast.patch

:gps, can you review the build system changes?

:dcamp, can you review the loader changes and the removal of escodegen?

:past, can you review the debugger changes?

:benvie, can you review the scratchpad changes?

Note that :benvie has already reviewed the pretty-fast library, and this patch is simply integrating that library with our tools and removing escodegen.

Try push: https://tbpl.mozilla.org/?tree=Try&rev=fd116e4f5937

Comment 8

[Dave Camp (:dcamp)]

Comment on attachment 826982 [details] [diff] [review]
pretty-fast.patch

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

r+ for the bits I was asked to review.

Comment 9

[Brandon Benvie [:benvie]]

Comment on attachment 826982 [details] [diff] [review]
pretty-fast.patch

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

Review for the Scratchpad bits:

::: browser/devtools/scratchpad/scratchpad.js
@@ +515,5 @@
>      return deferred.promise;
>    },
>  
> +  _prettyPrintWorker: null,
> +  get prettyPrintWorker() {

Needs a comment describing what the getter does.

@@ +526,5 @@
> +    }
> +    return this._prettyPrintWorker;
> +  },
> +
> +  _onPrettyPrintError: function ({ message, filename, lineno }) {

Inlining this function into `get prettyPrintWorker` would follow Scratchpad style better.

@@ +534,3 @@
>    /**
>     * Pretty print the source text inside the scratchpad.
>     */

Should add a @return type doc now that this returns a Promise.

@@ +540,5 @@
> +    const id = Math.random();
> +    const deferred = promise.defer();
> +
> +    const onReply = ({ data }) => {
> +      console.log(data.code);

Looks like you accidentally left this console.log in.

Comment 10

[Brandon Benvie [:benvie]]

Comment on attachment 826982 [details] [diff] [review]
pretty-fast.patch

For some reason when I added my review bugzilla morphed dcamp's r+ in a r? to me. Just removing that r?

Comment 11

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: pretty-fast.patch

With changes asked for by Benvie.

https://tbpl.mozilla.org/?tree=Try&rev=966f75536cf0

Comment 12

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 827014 [details] [diff] [review]
pretty-fast.patch

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

So we now have two copies of the source map library in the tree, right? How hard would it be to combine them, like DevToolsUtils.js/DevToolsUtils.jsm in a followup?

::: toolkit/devtools/server/actors/pretty-print-worker.js
@@ +12,4 @@
>   *
>   * Where `id` is a unique ID to identify this request, `url` is the url of the
>   * source being pretty printed, `indent` is the number of spaces to indent the
>   * code by, and `ast` is the source's abstract syntax tree.

This comment needs updating, too.

@@ +19,5 @@
>   *     { id, code, mappings }
>   *
>   * Where `id` is the same unique ID from the request, `code` is the pretty
>   * printed source text, and `mappings` is an array or source mappings from the
>   * pretty printed code to the AST's source locations.

Same here.

@@ +45,5 @@
>        mappings: prettified.map._mappings
>      });
>    } catch (e) {
>      self.postMessage({
> +      id: event.data.id,

Don't you already have |id| from the destructuring assignment in onmessage?

Comment 13

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

(In reply to Panos Astithas [:past] from comment #12)
> Comment on attachment 827014 [details] [diff] [review]
> pretty-fast.patch
> 
> Review of attachment 827014 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> So we now have two copies of the source map library in the tree, right? How
> hard would it be to combine them, like DevToolsUtils.js/DevToolsUtils.jsm in
> a followup?

We actually have two copies already because one copy was inlined into escodegen.worker.js.

This is a great idea, though. I was previously hoping to just use our loader, but this seems easier.

Filed bug 935366.

Comment 14

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

https://hg.mozilla.org/integration/fx-team/rev/5b70e599577c

Comment 15

[Phil Ringnalda (:philor)]

Backed out in  for making test_loader_paths.html say The built-in loader should have only one more mapping for testing. - got 15, expected 14 every time. ("one more" ... "15, expected 14"?)

Comment 16

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/integration/fx-team/rev/af4340134d87

Comment 17

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Forgot to add "acorn_loose" to the src dir loader... Relanded.

https://hg.mozilla.org/integration/fx-team/rev/9fd1c7feb8c0

Comment 18

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/9fd1c7feb8c0

Comment 19

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: aurora-pretty-fast.patch

This is the patch from this bug + the patch from bug 924466, rebased onto aurora.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 

Bug 762761

User impact if declined: 

The pretty printing feature will be incredibly slow.

Testing completed (on m-c, etc.):

Has been in m-c and all looks good. Tested locally and works as expected, and all relevant test suites pass.

Here is a try push: https://tbpl.mozilla.org/?tree=Try&rev=624202ecd076

Risk to taking this patch (and alternatives if risky): 

Low risk. We can always pref off the pretty printing feature if things go wrong. This patch doesn't really mess with any of the debugger or scratchpad internals, and so it is highly unlikely to break anything unrelated to pretty printing that is not covered by our existing tests.

String or IDL/UUID changes made by this patch:

None.

Comment 20

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: aurora-pretty-fast.patch

Correct try push: https://tbpl.mozilla.org/?tree=Try&rev=e81073c39a53

Comment 21

[bhavana bajaj [:bajaj]]

Comment on attachment 828287 [details] [diff] [review]
aurora-pretty-fast.patch

Given the low risk and keeping since we have alternatives here if this incurred serious regressions. Approving for uplift.

I am not sure how QA focuses on testing this area of dev tools, so please make sure to have some testing around this. You can also use "verifyme" keyword to get help on verification of a particular bug.

Comment 22

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/c6d43940a3ed

Comment 23

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Pretty printing large files used to take multiple seconds, now it should take less than a second.

Comment 24

[Bogdan Maris, Desktop QA]

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.8; rv:26.0) Gecko/20100101 Firefox/26.0
Mozilla/5.0 (X11; Linux i686; rv:26.0) Gecko/20100101 Firefox/26.0
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0

Using the nightly from 2013-10-23 and Firefox 26 Beta 1 I pretty printed http://code.jquery.com/jquery-1.10.2.js in the scretchpad and had a delay of about 2 seconds.
Using the latest Aurora 27.0a2 (buildID: 20131204004002) I pretty printed the same file in the scretchpad and had a delay for about a second.
This is a noticeable improvement but I could not reproduce the initial delay of multiple seconds (I think that there were more then 2 seconds delay). Could you provide a larger file maybe in order to see if this fix more easily or is this enough to call this verified fixed?

Comment 25

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Sorry, I should have been more clear. This is specifically within the debugger, not the scratchpad.

STR:

1. open http://canuckistani.github.io/st-beer/
2. Cmd + Opt + S to open the debugger
3. click on the app.js file on the left pane of the debugger.
3. click on the {} button on the bottom left

Expected:

The minified source is pretty printed in less than a second.

Previously:

The minified source took about 4-5 seconds to become pretty printed.

Comment 26

[Bogdan Maris, Desktop QA]

Thanks Nick.
Using your STR, the delay is very clear now on the builds before the fix. On latest Aurora 27.0a2 (buildID: 20131204004002) the delay is less then a second so this is verified as fixed.

Comment 27

[Bogdan Maris, Desktop QA]

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:27.0) Gecko/20100101 Firefox/27.0
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0
Mozilla/5.0 (X11; Linux i686; rv:27.0) Gecko/20100101 Firefox/27.0

On latest Aurora 28.0a2 (buildID: 2013121100400) the delay is less then a second as well.