Bug 128047

Summary: JSC profiler should show reasons for jettison
Product: WebKit Reporter: Filip Pizlo <fpizlo>
Component: JavaScriptCoreAssignee: Filip Pizlo <fpizlo>
Status: RESOLVED FIXED    
Severity: Normal CC: barraclough, bunhere, commit-queue, ggaren, gyuyoung.kim, mark.lam, mhahnenberg, mmirman, msaboff, nrotem, oliver, rakuco, sam
Priority: P2    
Version: 528+ (Nightly build)   
Hardware: All   
OS: All   
Bug Depends on:    
Bug Blocks: 128053, 128039    
Attachments:
Description Flags
work in progress
none
the patch ggaren: review+

Description Filip Pizlo 2014-02-01 11:34:55 PST
Patch forthcoming.
Comment 1 Filip Pizlo 2014-02-01 11:43:08 PST
Created attachment 222884 [details]
work in progress
Comment 2 Filip Pizlo 2014-02-01 14:04:15 PST
This is what it gives me.  Notice how you can now see, at a glance, all of the reasons why a code block was recompiled.

> log executeIteration
Compilation executeIteration#BBg0Fw-1-Baseline:
Compilation executeIteration#BBg0Fw-2-DFG:
    EXIT: at bc#87 due to InadequateCoverage, 1 times
    EXIT: at bc#123 due to InadequateCoverage, 2 times
    EXIT: at bc#649 due to InadequateCoverage, 1 times
    EXIT: at bc#179 due to BadFunction, 1 times
    Jettisoned due to BaselineLoopReoptimizationTrigger
Compilation executeIteration#BBg0Fw-3-DFG:
    EXIT: at bc#1055 due to InadequateCoverage, 1 times
Compilation executeIteration#BBg0Fw-4-FTLForOSREntry:
Compilation executeIteration#BBg0Fw-5-FTL:
    Jettisoned due to WeakReference
Compilation executeIteration#BBg0Fw-6-DFG:
Compilation executeIteration#BBg0Fw-7-FTL:
    EXIT: at bc#79 --> checkIRQMatching#ENZlEebc#1 due to BadCache, 54 times
    EXIT: at bc#716 --> checkIRQMatching#ENZlEebc#1 due to BadCache, 25 times
    Jettisoned due to WeakReference
Compilation executeIteration#BBg0Fw-8-FTLForOSREntry:
Compilation executeIteration#BBg0Fw-9-DFG:
Compilation executeIteration#BBg0Fw-10-FTLForOSREntry:
Compilation executeIteration#BBg0Fw-11-FTL:
    Jettisoned due to WeakReference
Comment 3 Filip Pizlo 2014-02-01 14:10:09 PST
It's even better when I add counts.  Notice that you can now see some obvious stupidity going on here.  Probably we're failing to hash-cons some crucial structures.

> log executeIteration
Compilation executeIteration#BBg0Fw-1-Baseline:
    Total count: 37692287  Max count: 444588
Compilation executeIteration#BBg0Fw-2-DFG:
    Total count: 2931054  Max count: 32885
    EXIT: at bc#87 due to InadequateCoverage, 1 times
    EXIT: at bc#123 due to InadequateCoverage, 2 times
    EXIT: at bc#649 due to InadequateCoverage, 1 times
    EXIT: at bc#179 due to BadFunction, 1 times
    Jettisoned due to BaselineLoopReoptimizationTrigger
Compilation executeIteration#BBg0Fw-3-DFG:
    Total count: 14441184  Max count: 169676
    EXIT: at bc#1055 due to InadequateCoverage, 1 times
Compilation executeIteration#BBg0Fw-4-FTLForOSREntry:
    Total count: 0  Max count: 0
Compilation executeIteration#BBg0Fw-5-FTL:
    Total count: 0  Max count: 0
    Jettisoned due to WeakReference
Compilation executeIteration#BBg0Fw-6-DFG:
    Total count: 29596525  Max count: 348302
Compilation executeIteration#BBg0Fw-7-FTL:
    Total count: 71610674  Max count: 843708
    EXIT: at bc#79 --> checkIRQMatching#ENZlEebc#1 due to BadCache, 54 times
    EXIT: at bc#716 --> checkIRQMatching#ENZlEebc#1 due to BadCache, 25 times
    Jettisoned due to WeakReference
Compilation executeIteration#BBg0Fw-8-FTLForOSREntry:
    Total count: 0  Max count: 0
Compilation executeIteration#BBg0Fw-9-DFG:
    Total count: 29435856  Max count: 346420
Compilation executeIteration#BBg0Fw-10-FTLForOSREntry:
    Total count: 375213  Max count: 4408
Compilation executeIteration#BBg0Fw-11-FTL:
    Total count: 323554095  Max count: 3810030
    Jettisoned due to WeakReference
Comment 4 Filip Pizlo 2014-02-01 14:19:26 PST
Created attachment 222892 [details]
the patch
Comment 5 Geoffrey Garen 2014-02-01 14:45:38 PST
Comment on attachment 222892 [details]
the patch

r=me

Not really clear what "Total count" and "Max count" mean.
Comment 6 Filip Pizlo 2014-02-01 18:17:43 PST
(In reply to comment #5)
> (From update of attachment 222892 [details])
> r=me
> 
> Not really clear what "Total count" and "Max count" mean.

Yeah.  display-profiler-output currently uses "max count" for a lot of things.  It means: if you count the number of times each bytecode instruction inside the machine code (i.e. it may include bytecode instructions inlined from other code blocks) has executed, then take the max of that.  The benefit of max count is that it will typically tell you how hot the hottest loop inside the function is.  Gavin never really liked the max and preferred the total, and we sort of agreed - 1.5 years ago? - that we would think this through more deeply and pick a better way of characterizing function hotness.  Someone still needs to figure it out.  So I just filed: https://bugs.webkit.org/show_bug.cgi?id=128053

For now, I'll just land this as is - more information is better.  But yeah, it's important that we figure out what to do about this.  I've just never seen a profiler get this quite right, so I don't have context for how to make the right choice, at the moment.
Comment 7 Filip Pizlo 2014-02-01 18:19:09 PST
Looks like the Mac EWS failures are because I used "Project" instead of "Private" for the new header.  Fixed.
Comment 8 Filip Pizlo 2014-02-01 18:20:58 PST
Landed in http://trac.webkit.org/changeset/163254