1265526 - Performance Profiler doesn't sometimes show time spent in asm.js code on the page unless "Show Gecko Platform Data" is enabled.

Status: RESOLVED FIXED

(DevTools :: Performance Tools (Profiler/Timeline), defect, P2)

Description

[Jukka Jylänki]

Test page: https://dl.dropboxusercontent.com/u/40949268/emcc/10kCubes_no_vsync_little_garbage/10kCubes.html

Comparing built-in profiler to geckoprofiler, with both profilers in the same "JavaScript only" and "Bottom-up view" modes:

Geckoprofiler: https://dl.dropboxusercontent.com/u/40949268/dump/geckoprofiler_bottomupview_javascript_only.png

Shows glDrawArrays() as the biggest bottleneck on the page, 68.7%, called from two different call sites: Graphics::Render(VertexBuffer), which accounts for 65.1%-units, and Graphics::ApplyAndRender(VertexBuffer), which accounts for the remaining 3.6%-units.

Built-in profiler: https://dl.dropboxusercontent.com/u/40949268/dump/builtinprofiler_bottomupview_javascript_only.png

Shows glDrawArrays as being called by Runtime.dynCall, which takes up 40.57% of the time.

It looks like the built-in profiler is not displaying the asm.js functions at all, unless Show Gecko Platform Data is checked. User asm.js code is not Gecko Platform Data, so I don't think it should be necessary to tick that checkbox in order to show asm.js code?

Comment 1

[Luke Wagner [:luke]]

[Tracking Requested - why for this release]:

I think the cause is pretty simple here: it looks like the demangling of names produces stack strings that don't match the regex that classifies frames as JS vs. Gecko.  That is, if you run minified asm.js (without the mangled names), the asm.js shows up just fine.  So I think the fix is probably just to tweak the output of the demangler.

Given how easy it is to fix and that this will be pretty confusing the users, it'd be great to fix in FF53.

Comment 2

[Liz Henry (:lizzard) (relman/hg->git project)]

Greg, can you help find someone to fix this? Thanks!  Maybe in 54 if not 53.

Comment 3

[Greg Tatum [:gregtatum]]

I can't seem to reproduce this. The original link doesn't work, and when I'm profiling some random ASM.js examples, the ASM codes SEEMS to be in there, although it's hard to separate what's normal JS and what's ASM.

Comment 4

[Greg Tatum [:gregtatum]]

Jukka: Do you have a link to a ZIP of this or something? Dropbox won't let me load this as a webpage anymore.

Comment 5

[Jukka Jylänki]

Looks like since this was originally reported, Dropbox has changed their behavior to not allow hosting .html files anymore.

Visit https://s3.amazonaws.com/mozilla-games/tmp/2016-05-02-SunTemple-profiling/SunTemple-HTML5-Shipping.html as another test case. (patience when loading, on first run it caches ~100MB of assets to IndexedDB)

Comment 6

[Greg Tatum [:gregtatum]]

So I spent some time looking into this, and didn't get a clear result. I'm focusing on the next iteration on Mozilla's performance tooling with perf.html, and so I'm not spending as much time looking at this code, but I would like to help here if I can. It appeared that some of the ASM samples were being correctly labeled, and some not. It's very ambiguous looking at a profile with ASM samples mixed with platform samples. If someone could provide a very clear STR, with specific functions that are not being labeled correctly then I'll look into this again, otherwise I'm going to put this on hold as I'm focused on P0 perf work that will eventually make this problem go away.

Comment 7

[Luke Wagner [:luke]]

Thanks for looking into this!  Actually, I just hit a really clear case of this yesterday: if you go to webassembly.org/demo, click "Play" and then profile while the game is running, *everything* is being classified as Gecko Platform Data and so nothing shows up (except the high-level categories like "JIT") by default.

Comment 8

[Jukka Jylänki]

Attachment: profiler_wasm_code.png

One test case is here: https://s3.amazonaws.com/mozilla-games/ZenGarden/EpicZenGarden.html?novsync&cpuprofiler

That runs WebAssembly and regular JS, no asm.js. Annotated the attached screenshot to show the code.

Comment 9

[Jukka Jylänki]

Attachment: profiler_asmjs_code.png

Same application can be visited as asm.js here:

https://s3.amazonaws.com/mozilla-games/ZenGarden/EpicZenGarden.html?novsync&cpuprofiler&asmjs

Annotated a profiling run of that version in the attached screenshot.

Comment 10

[Jukka Jylänki]

Marked down bug 1349247 for the WebAssembly function names.

Comment 11

[Greg Tatum [:gregtatum]]

Wow, great STR, thanks Jukka. Will take some time later this week or next to take another poke at this. I also sent both you emails about performance tooling roadmap so you all are aware.

Comment 12

[Liz Henry (:lizzard) (relman/hg->git project)]

Too late for a fix for 53. We could still take a patch for 54/55.

Comment 13

[Julien Cristau [:jcristau]]

Greg, any update here since comment 11?

Comment 14

[Gerry Chang [:gchang]]

Mark 54 won't fix as it's late for Beta54.

Comment 15

[Greg Tatum [:gregtatum]]

Attachment: Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

asm.js and wasm frames were not being correctly identified as user
content in the perf devtool. This patch correctly finds blob urls that
were being mis-identified as platform content, and wasm frames, which do
not have any identifying information other than their function name
containing wasm-function.

Review commit: https://reviewboard.mozilla.org/r/144176/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/144176/

Comment 16

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/144176/diff/1-2/

Comment 17

[Greg Tatum [:gregtatum]]

It turns out the blob URLs were not categorized correctly in this case. I also added a function to sniff for "wasm-function" frame names. asm.js and wasm should probably use the "implementation" property in the Gecko Profiler to correctly label them. I will file follow-ups there.

Comment 18

[Julien Wajsberg [:julienw]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

https://reviewboard.mozilla.org/r/144176/#review148314

I'm not sure of what I see when I try the patch on the WASM demo. I think I see wasm content either under Gecko or under JIT or at the top level. _But_ I see it without checking "show Gecko Platform data" and I think this is the goal of the patch, so this looks good.

Some comments and questions below.

::: devtools/client/performance/modules/logic/frame-utils.js:224
(Diff revision 2)
>    } else {
>      // Cases 2) and 3)
>      schemeStartIndex = 0;
>    }
>  
> -  if (isContentScheme(location, schemeStartIndex)) {
> +  if (isContentScheme(location, schemeStartIndex) || isWASM(location)) {

Don't you think the `isWASM` check could be in `isContentScheme` ?

Another open question: is WASM data always "content"? What about WASM from addons or from the firefox code?

Can we know where the WASM data comes from, surely this comes from a specific URL?

::: devtools/client/shared/source-utils.js:14
(Diff revision 2)
>  const UNKNOWN_SOURCE_STRING = l10n.getStr("frame.unknownSource");
>  
>  // Character codes used in various parsing helper functions.
>  const CHAR_CODE_A = "a".charCodeAt(0);
>  const CHAR_CODE_C = "c".charCodeAt(0);
> +const CHAR_CODE_B = "b".charCodeAt(0);

nit: this line should be before the CHAR_CODE_C

::: devtools/client/shared/source-utils.js
(Diff revision 2)
>           location.charCodeAt(++i) === CHAR_CODE_COLON;
>  }
>  
> -function isContentScheme(location, i = 0) {
> +function isContentScheme(location, i = 0, isRecursed = false) {
>    let firstChar = location.charCodeAt(i);
> -

nit: please keep this empty line

::: devtools/client/shared/source-utils.js:263
(Diff revision 2)
> +        location.charCodeAt(++i) == CHAR_CODE_L &&
> +        location.charCodeAt(++i) == CHAR_CODE_O &&
> +        location.charCodeAt(++i) == CHAR_CODE_B &&
> +        location.charCodeAt(++i) == CHAR_CODE_COLON
> +      ) {
> +        if (isRecursed) {

if we keep this behavior (and I'm not sure we should, see my comment in the test file), I'd like a comment explaining the rationale here.

::: devtools/client/shared/source-utils.js:266
(Diff revision 2)
> +        location.charCodeAt(++i) == CHAR_CODE_COLON
> +      ) {
> +        if (isRecursed) {
> +          return false;
> +        }
> +        return isContentScheme(location, i + 1, true);

same here, I'd like a comment explaining the recursive behavior with an example.

::: devtools/client/shared/source-utils.js:322
(Diff revision 2)
>        return false;
>    }
>  }
>  
> +function isWASM(location) {
> +  let i = 0;

nit: for a more generic function and an approach more consistent to other functions in this file, how about taking `i` as parameter, with `0` as default value?

::: devtools/client/shared/test/unit/test_source-utils.js:53
(Diff revision 2)
>    }
>    for (let url of CONTENT_URLS) {
>      ok(sourceUtils.isContentScheme(url), `${url} correctly identified as content scheme`);
>    }
> +  ok(!sourceUtils.isContentScheme("blob:blob:http://mozilla.org"),
> +     "Only matches one blob:");

When does this happens? Is it when for example an HTML blob is being loaded in an iframe, and itself handles a blob? Shouldn't this case be categorized as content too ?

Comment 19

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/144176/diff/2-3/

Comment 20

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

https://reviewboard.mozilla.org/r/144176/#review149754

::: devtools/client/performance/modules/logic/frame-utils.js:224
(Diff revision 2)
>    } else {
>      // Cases 2) and 3)
>      schemeStartIndex = 0;
>    }
>  
> -  if (isContentScheme(location, schemeStartIndex)) {
> +  if (isContentScheme(location, schemeStartIndex) || isWASM(location)) {

I don't think we can know the origin at this time, so it's probably better to show it as content.

I'd prefer to keep isWASM as a separate check here, since it's not a true "isContentScheme" check.

I'll add a comment here to clarify what's going on.

::: devtools/client/shared/source-utils.js:14
(Diff revision 2)
>  const UNKNOWN_SOURCE_STRING = l10n.getStr("frame.unknownSource");
>  
>  // Character codes used in various parsing helper functions.
>  const CHAR_CODE_A = "a".charCodeAt(0);
>  const CHAR_CODE_C = "c".charCodeAt(0);
> +const CHAR_CODE_B = "b".charCodeAt(0);

ABCDEFGHIJKLMNOPQRSTUVWXYZ. ;)

::: devtools/client/shared/source-utils.js
(Diff revision 2)
>           location.charCodeAt(++i) === CHAR_CODE_COLON;
>  }
>  
> -function isContentScheme(location, i = 0) {
> +function isContentScheme(location, i = 0, isRecursed = false) {
>    let firstChar = location.charCodeAt(i);
> -

Spent a good hour making my prettified diffs show me these changes now.

::: devtools/client/shared/source-utils.js:266
(Diff revision 2)
> +        location.charCodeAt(++i) == CHAR_CODE_COLON
> +      ) {
> +        if (isRecursed) {
> +          return false;
> +        }
> +        return isContentScheme(location, i + 1, true);

Let's just drop all of this recursion check to simplify this code.

Comment 21

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/144176/diff/3-4/

Comment 22

[Julien Wajsberg [:julienw]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

https://reviewboard.mozilla.org/r/144176/#review150814

r=me but please fix the latest nits before landing :)

::: devtools/client/performance/modules/logic/frame-utils.js:225
(Diff revision 4)
>      // Cases 2) and 3)
>      schemeStartIndex = 0;
>    }
>  
> -  if (isContentScheme(location, schemeStartIndex)) {
> +  // We can't know if WASM frames are content or not at the time of this writing, so label
> +  // them all as content.

Is it worth filing a separate bug to make this possible ?
If yes, please file it and add the bug # in this comment.

::: devtools/client/shared/source-utils.js:264
(Diff revision 4)
> +        location.charCodeAt(++i) == CHAR_CODE_L &&
> +        location.charCodeAt(++i) == CHAR_CODE_O &&
> +        location.charCodeAt(++i) == CHAR_CODE_B &&
> +        location.charCodeAt(++i) == CHAR_CODE_COLON
> +      ) {
> +        return isContentScheme(location, i + 1, true);

nit: you can remove the last argument, now :)

Comment 23

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/144176/diff/4-5/

Comment 24

[Greg Tatum [:gregtatum]]

Comment on attachment 8872636 [details]
Bug 1265526 - Correctly categorize blob URLs and wasm frames as user content;

https://reviewboard.mozilla.org/r/144176/#review150814

> Is it worth filing a separate bug to make this possible ?
> If yes, please file it and add the bug # in this comment.

I don't think it's worth filing at this time, as perf.html doesn't make this distinction at the time, and we're in maintenance mode for this tool. We definitely need to follow-up at some point with the way we handle WASM in the profiler.

Comment 25

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d218a8cbd8f7
Correctly categorize blob URLs and wasm frames as user content; r=julienw

Comment 26

[Julien Wajsberg [:julienw]]

> I don't think it's worth filing at this time, as perf.html doesn't make this distinction at the time, and we're in maintenance mode for this tool. We definitely need to follow-up at some point with the way we handle WASM in the profiler.

That's what I meant: if we want to be able to discriminate these frames in the future, it may be worth filing a bug now :)

Comment 27

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/d218a8cbd8f7