Bug 183982 - [JSC] Add options to report parsing and bytecode compiling times
Summary: [JSC] Add options to report parsing and bytecode compiling times
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: New Bugs (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Yusuke Suzuki
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2018-03-24 06:50 PDT by Yusuke Suzuki
Modified: 2018-03-24 12:29 PDT (History)
9 users (show)

See Also:


Attachments
Patch (18.50 KB, patch)
2018-03-24 06:52 PDT, Yusuke Suzuki
mark.lam: review+
Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Yusuke Suzuki 2018-03-24 06:50:29 PDT
[JSC] Add options to report parsing and bytecode compiling times
Comment 1 Yusuke Suzuki 2018-03-24 06:52:35 PDT
Created attachment 336472 [details]
Patch
Comment 2 Mark Lam 2018-03-24 11:24:18 PDT
Comment on attachment 336472 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=336472&action=review

r=me with issues addressed.

> Source/JavaScriptCore/bytecode/ParseHash.cpp:50
> +    if (!hashForCall)
> +        hashForCall = 1;
> +    if (!hashForConstruct)
> +        hashForConstruct = 1;

CodeForCall has value 0, and CodeForConstruct has value 1.  The only way that hashForCall is 0 is if hash is 0, which means that hasForConstruct being 0 ^ 1 i.e. 1.  Similarly, if hash has value 1, then both hashForCall and hashForConstruct will end up having the same value of 1.  Is this intentional?  

My gut feeling is that there's more value in having hashForCall and hashForConstruct being different.  If either hashForCall or hashForConstruct is 0, I suggest using a different value like 0xbb4472, which prints as #AAzero once it goes thru our integerToSixCharacterHashString() conversion.  This way one will be #AAzero when the other is #AAAAAB (i.e. 0x1).

Sidenote: I would prefer a snazzier hash like #zzzero or #zerooo or #00zero or #zero00 (or uppercase equivalents), but alas, those are not encodable in an unsigned hash value.  So, #AAzero is the best we can do. =(

> Source/JavaScriptCore/bytecompiler/BytecodeGenerator.h:392
> +            if (result.isValid())
> +                return result;

You're returning early when the result is valid i.e. under normal circumstance, we'll never report the byte code compile times.  I think you meant to test !result.isValid() instead.

On that note, would we want to also dump failed compile times (with a "Failed to compile " header instead) when the result is invalid?  We did consume time compiling after all.  I'm not insisting on this, but just wanted to share the thought for consideration.

> Source/JavaScriptCore/bytecompiler/BytecodeGenerator.h:396
> +                dataLog("Compiled #", CodeBlockHash(sourceCode, unlinkedCodeBlock->isConstructor() ? CodeForConstruct : CodeForCall), " into bytecode ", bytecodeGenerator->instructions().size(), " instructions in ", (after - before).milliseconds(), " ms.\n");

FYI, alternatively, you can just use dataLogLn() and leave out the "\n" at the end.

> Source/JavaScriptCore/parser/Parser.h:1978
> +    if (UNLIKELY(!result))
>          return result;

Ditto.  Would we want to also dump "failed parse" times?

> Source/JavaScriptCore/parser/Parser.h:1983
> +        dataLog("Parsed #", hash.hashForCall(), "/#", hash.hashForConstruct(), " in ", (after - before).milliseconds(), " ms.\n");

Ditto. You can alternately use dataLogLn() and leave out the "\n" at the end.
Comment 3 Yusuke Suzuki 2018-03-24 11:41:05 PDT
Comment on attachment 336472 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=336472&action=review

>> Source/JavaScriptCore/bytecode/ParseHash.cpp:50
>> +        hashForConstruct = 1;
> 
> CodeForCall has value 0, and CodeForConstruct has value 1.  The only way that hashForCall is 0 is if hash is 0, which means that hasForConstruct being 0 ^ 1 i.e. 1.  Similarly, if hash has value 1, then both hashForCall and hashForConstruct will end up having the same value of 1.  Is this intentional?  
> 
> My gut feeling is that there's more value in having hashForCall and hashForConstruct being different.  If either hashForCall or hashForConstruct is 0, I suggest using a different value like 0xbb4472, which prints as #AAzero once it goes thru our integerToSixCharacterHashString() conversion.  This way one will be #AAzero when the other is #AAAAAB (i.e. 0x1).
> 
> Sidenote: I would prefer a snazzier hash like #zzzero or #zerooo or #00zero or #zero00 (or uppercase equivalents), but alas, those are not encodable in an unsigned hash value.  So, #AAzero is the best we can do. =(

Yes, right now, this is the same to CodeBlockHash's algorithm, which is important to track the same source consistently with the same hash.
"#AAzero" sounds good. I'll change CodeBlockHash too.

>> Source/JavaScriptCore/bytecompiler/BytecodeGenerator.h:392
>> +                return result;
> 
> You're returning early when the result is valid i.e. under normal circumstance, we'll never report the byte code compile times.  I think you meant to test !result.isValid() instead.
> 
> On that note, would we want to also dump failed compile times (with a "Failed to compile " header instead) when the result is invalid?  We did consume time compiling after all.  I'm not insisting on this, but just wanted to share the thought for consideration.

A bit interestingly, this result is ParserError. So result.isValid() means we failed to generate bytecodes.
Reporting "Failed to compile" case sounds reasonable. I'll add this.

>> Source/JavaScriptCore/bytecompiler/BytecodeGenerator.h:396
>> +                dataLog("Compiled #", CodeBlockHash(sourceCode, unlinkedCodeBlock->isConstructor() ? CodeForConstruct : CodeForCall), " into bytecode ", bytecodeGenerator->instructions().size(), " instructions in ", (after - before).milliseconds(), " ms.\n");
> 
> FYI, alternatively, you can just use dataLogLn() and leave out the "\n" at the end.

Fixed.

>> Source/JavaScriptCore/parser/Parser.h:1978
>>          return result;
> 
> Ditto.  Would we want to also dump "failed parse" times?

Added.

>> Source/JavaScriptCore/parser/Parser.h:1983
>> +        dataLog("Parsed #", hash.hashForCall(), "/#", hash.hashForConstruct(), " in ", (after - before).milliseconds(), " ms.\n");
> 
> Ditto. You can alternately use dataLogLn() and leave out the "\n" at the end.

Fixed.
Comment 4 Yusuke Suzuki 2018-03-24 12:04:23 PDT
Committed r229952: <https://trac.webkit.org/changeset/229952>
Comment 5 Radar WebKit Bug Importer 2018-03-24 12:05:15 PDT
<rdar://problem/38829993>
Comment 6 Mark Lam 2018-03-24 12:20:26 PDT
(In reply to Yusuke Suzuki from comment #4)
> Committed r229952: <https://trac.webkit.org/changeset/229952>

Oh, I didn't think you were going to fix the hash before you xor in the CodeForCall/Construct:

    if (hash == 0 || hash == 1)
        hash += 0xbb4472;

May I suggest a different constant instead:

    if (hash == 0 || hash == 1)
        hash += 0x2d5a93d0; // Ensures a non-zero hash, and gets us #Azero0 for CodeForCall and #Azero1 for CodeForConstruct.

Please also add that comment so that it'll be clear why we chose this odd constant.  rs=me to just change this in a follow up patch.
Comment 7 Yusuke Suzuki 2018-03-24 12:29:08 PDT
Committed r229953: <https://trac.webkit.org/changeset/229953>