881882 - OdinMonkey: report compile time and slow functions in asm.js success message

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Luke Wagner [:luke]]

Attachment: patch

Until bug 875174, it'll be useful to report which functions are taking forever to compile so that they can be out-of-lined from the asm.js module (and thus avoid mandatory Ion compilation).  This patch includes this information at the end of the "Successfully compiled asm.js" console message.

Note: parallel compilation makes all functions take longer and the timing has more variance.  Toggle javascript.options.ion.parallel_compilation to get a more accurate measurement.

Comment 1

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

erm, pretty sure that won't work on Windows... use PR_Now() or whatever the JS equivalent is?

Comment 2

[Luke Wagner [:luke]]

JS_Now (in jsapi.h) uses PRMJ_Now and I see a (rather long and involved) implementation on Windows.

Comment 3

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Yeah, I think on windows it uses QueryPerformanceCounter and does the right goop to get the highest precision possible.  You could just use QPC directly on windows for timing; it'll be incorrect on some platforms, but we don't really care about those.  QPC should be quite fast to call directly.

Comment 4

[Luke Wagner [:luke]]

... or I could just keep PRMJ_Now and avoid platform-specific #ifdefs :)  The performance and precision of these calls isn't particularly important.

Comment 5

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Oh, yeah, that sounds good.  I thought you were trying to get to really low-impact, but PRMJ_Now should be fine on Windows as well in normal usage.

Comment 6

[Luke Wagner [:luke]]

Attachment: rm JS_ASMJS

This is a minor cleanup (since now JS_ION iff JS_ASMJS) that came up while writing the main patch.

Comment 7

[Sean Stangl [:sstangl]]

I'm assuming that the patch from Comment 0 needs refreshing with use of PRMJ_Now() and friends before review.

Comment 8

[Luke Wagner [:luke]]

Oh, HAH, I see what Vlad was going on about, the patch in comment 0 is totally my weeks-old ad hoc measurement patch!  (I was like, "comeon dude, PRMJ_Now will totally work on windows, that's the point".)  The REAL patch is totally different (and rather more involved).

Comment 9

[Luke Wagner [:luke]]

Attachment: real patch

Comment 10

[Sean Stangl [:sstangl]]

Comment on attachment 761573 [details] [diff] [review]
real patch

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

::: js/src/ion/AsmJS.cpp
@@ +1256,5 @@
>      }
>  
> +    static const unsigned SLOW_FUNCTION_THRESHOLD_MS = 250;
> +
> +    bool reportCompileTime(ParseNode *fn, unsigned ms) {

maybeReportCompileTime()?

@@ +1483,5 @@
>  
> +    void buildCompilationTimeReport(ScopedJSFreePtr<char> *out) {
> +        ScopedJSFreePtr<char> slowFuns;
> +        if (!slowFunctions_.empty()) {
> +            slowFuns.reset(JS_smprintf("; %d slow functions: ", slowFunctions_.length()));

"slow functions" could mean that the functions execute slowly. Maybe "%d functions compile slowly:"?

@@ +1491,5 @@
> +                SlowFunction &func = slowFunctions_[i];
> +                JSAutoByteString name;
> +                if (!js_AtomToPrintableString(cx_, func.name, &name))
> +                    return;
> +                slowFuns.reset(JS_smprintf("%s%s:%u:%u (%ums)%s", slowFuns.get(),

This is pretty gross. Is there some reason why we can't just allocate a large buffer and snprintf into it?

@@ +1492,5 @@
> +                JSAutoByteString name;
> +                if (!js_AtomToPrintableString(cx_, func.name, &name))
> +                    return;
> +                slowFuns.reset(JS_smprintf("%s%s:%u:%u (%ums)%s", slowFuns.get(),
> +                                           name.ptr(), func.line, func.column, func.ms,

It may also be interesting to show each function's compilation time as % of total compilation time.

Comment 11

[Luke Wagner [:luke]]

Great suggestions, thanks.

https://hg.mozilla.org/integration/mozilla-inbound/rev/00a8c9c3fe5d
https://hg.mozilla.org/integration/mozilla-inbound/rev/f8f6c2b1a92e

Comment 12

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/00a8c9c3fe5d
https://hg.mozilla.org/mozilla-central/rev/f8f6c2b1a92e

Comment 13

[Luke Wagner [:luke]]

Actually, the percentages are rather misleading in the default (parallel compilation) mode since they can add up to more than 100%.  There also isn't a simple way to fix it (summing up the totals of all the slow functions only tells you the % of slow time, what we'd need is to sum up total parallel compilation time).  For now, just removing:

https://hg.mozilla.org/integration/mozilla-inbound/rev/5527906f11f5

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/5527906f11f5

Comment 15

[Luke Wagner [:luke]]

Well, overall the bug is fixed (times are reported).  The only thing removed in comment 13 was the percentages.

Comment 16

[Cameron Kaiser [:spectre]]

Is there a reason JS_ASMJS couldn't be made optional again, or a compile-time option? Now, to get BaselineCompiler working, I have to implement ASMJS also (even though I'm not using it), and I didn't have to before.

I would gladly submit a patch for this, but I want to know if I should bother first. Right now I have it disabled in my PPC build while I try to get Baseline off the ground.

Comment 17

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

(This is the wrong place for that question [js groups better], but please no -- fewer compile flags the better.  I understand it's more burden when porting, but it makes life simpler and more consistent in the long run.)

Comment 18

[Cameron Kaiser [:spectre]]

So much for ease of portability.

Comment 19

[Luke Wagner [:luke]]

There is another bug (can't find it) where we talked about having separate JS_BASELINE_JIT and JS_ION flags, which is, it sounds like, what you really want.  Several people want this so I think we'd be happy to have those patches (in a separate bug, though).

Comment 20

[Cameron Kaiser [:spectre]]

Yes, that would be fine (I'm pretty much implementing that anyway). I can spin it into another bug, but I can't find anything else referencing a JS_BASELINE_JIT flag. I'll open a new one if no one remembers where it is.

Comment 21

[Luke Wagner [:luke]]

Yeah, I don't remember where it is, new bug sounds right.  cc me and :jandem