RFR: Rework rich PrintCompilation logs [v2]

Vladimir Kozlov kvn at openjdk.org
Fri Sep 6 20:29:17 UTC 2024


On Fri, 6 Sep 2024 19:54:30 GMT, Aleksey Shipilev <shade at openjdk.org> wrote:

>> I have been studying javac benchmark behavior, and current `PrintCompilation` logs are very useful to figure out how much time is spent in creation, queueing, work time for each task. Current logs are quite a bit confusing, though:
>>  - The columns are misindented
>>  - The precision is too low to capture short events: most of the times are zero
>>  - Output seems to rely on "now" timestamp, which depends on _when_ we print
>>  
>> This PR reworks the logs to be more straightforward.
>> 
>> Example before:
>> 
>> 
>>    S296 C0 Q229 3531      A  2       com.sun.tools.javac.parser.JavacParser::typeName (37 bytes)
>>    S296 C0 Q245 2030      A  2       com.sun.tools.javac.tree.TreeInfo::innermostType (102 bytes)
>>    S296 C0 Q0 4169         3       com.sun.tools.javac.comp.Flow$AliveAnalyzer$$Lambda/0x800000105::accept (12 bytes)
>>    S296 C0 Q245 2042      A  2       com.sun.tools.javac.tree.JCTree$JCPrimitiveTypeTree::accept (9 bytes)
>>    S296 C0 Q0 4170         3       com.sun.tools.javac.comp.Flow$AssignAnalyzer$$Lambda/0x800000108::accept (12 bytes)
>>    S296 C0 Q0 4171         3       com.sun.tools.javac.comp.Flow$FlowAnalyzer$$Lambda/0x80000010a::accept (12 bytes)
>>    S296 C0 Q245 2098      A  2       com.sun.tools.javac.code.Symbol$RecordComponent::getOriginalAnnos (24 bytes)
>>    S296 C0 Q244 2348      A  2       com.sun.tools.javac.tree.TreeCopier::visitPrimitiveType (24 bytes)
>>    S296 C0 Q244 2349      A  2       com.sun.tools.javac.tree.TreeCopier::visitPrimitiveType (7 bytes)
>> 
>> 
>> Example after:
>> 
>> 
>>     386    W0.0  Q313.7    C0.2   3524   !  A  2       com.sun.tools.javac.parser.JavacParser::literal (655 bytes)
>>     386                           3858         3       java.util.stream.MatchOps$$Lambda/0x800000030::<init> (15 bytes)   made not entrant
>>     386    W0.1                   2416      A  1       com.sun.tools.javac.comp.Infer$CheckInst::boundsToCheck (5 bytes)
>>     386    W0.0    Q0.1    C0.2   4155         4       java.util.stream.MatchOps$$Lambda/0x800000030::<init> (15 bytes)
>>     386    W0.1  Q332.7    C0.0   2416      A  1       com.sun.tools.javac.comp.Infer$CheckInst::boundsToCheck (5 bytes)
>>     386    W0.2                   2902      A  2       com.sun.tools.javac.code.ClassFinder::classFileNotFound (13 bytes)
>>     386    W0.2  Q327.9    C0.0   2902      A  2       com.sun.tools.javac.code.ClassFinder::classFileNotFound (13 bytes)
>>     386    W0.0                   3527      A  2       com.sun.tools.javac.parser.Java...
>
> Aleksey Shipilev has updated the pull request incrementally with one additional commit since the last revision:
> 
>   Swap W<->C

Good.

-------------

Marked as reviewed by kvn (Committer).

PR Review: https://git.openjdk.org/leyden/pull/16#pullrequestreview-2287108897


More information about the leyden-dev mailing list