Bug 112988 – JSC profiler should have an at-a-glance report of the success of DFG optimization

• Status: RESOLVED
• Resolution: FIXED
• Component: JavaScriptCore

[Filip Pizlo]

It should report the number of inlined GetByIds, PutByIds, and Calls in the DFG.

[Filip Pizlo]

Created attachment 194401 [details]
the patch

[Filip Pizlo]

Example output:

[pizlo@dethklok OpenSource] Tools/Scripts/display-profiler-output deltablue.profile 
          CodeBlock            #Instr  Source Counts    Machine Counts  #Compil  Inlines  #Exits  Recent Opts                        Source                        
                                          Base/DFG         Base/DFG             Src/Total           G/P/C/M  
         size#DCkJLC             24     67/18026927        67/51988        2      17/41      0      1/0/0/0   function () { return this.elms.length; }
          at#C3TUO6              21     67/14911927        67/44751        2      10/26      0      1/0/0/0   function (index) { return this.elms[index]; }
        output#CKTGff            56     884/13716222     884/2516778       4       4/9      314     1/0/0/0   function () { return (this.direction == Direction.FOR
         size#EJQJjM             33     67/12299927         67/895         2      7/13       0      3/0/1/0   function () { return this.v.size(); }
     constraintAt#BFWFPX         36     67/12159927         67/885         2      7/13       0      3/0/1/0   function (index) { return this.v.at(index); }
        execute#BrpnW7          104     865/12159042     865/1461301       2      5/12       0     12/0/6/0   function () { for (var i = 0; i < this.size(); i++) {
         input#AMNJAd            56     437/11706680       437/342         3      5/10      201     1/0/0/0   function () { return (this.direction == Direction.FOR
        execute#CNoE25           66     78/10199927      78/10000039       2       2/2       0      9/1/2/0   function () { this.output().value = this.input().valu
          add#BAffrf             33      67/2342927        67/15589        2      17/41      0      2/0/1/0   function (elm) { this.elms.push(elm); }
        execute#ES9SmN          202     114/2321880      114/2321880       2       0/0       0     16/2/0/0   function () { if (this.direction == Direction.FORWARD
           #Bys3HT              153     801/1728495       801/12452        3       1/4      302    11/0/5/0   function (v, coll) { var determining = v.determinedBy
      isSatisfied#DcAQMs         33     301/1710694      301/1689320       3       2/4      101     1/0/0/0   function () { return this.direction != Direction.NONE
      removeFirst#DJ4I9h         33      67/1220927        67/16684        2       1/6       0      2/0/1/0   function () { return this.elms.pop(); }
        weaker#ARC9cl            25      67/1204927        67/1479         2       4/7       0      2/0/0/0   function (s1, s2) { return s1.strengthValue > s2.stre
   OrderedCollection#CjbgyO      47      502/833592        502/1164        2      6/22      101     0/1/0/0   function OrderedCollection() { this.elms = new Array(
       weakestOf#BI04sI          44      67/803927          67/158         2       2/3       0      3/0/1/0   function (s1, s2) { return this.weaker(s1, s2) ? s1 :
     addPropagate#Aj89I2        233     9220/698975      9220/1105167      4       0/0       0     23/1/13/0  function (c, mark) { var todo = new OrderedCollection
       stronger#DVK8sV           25      67/707927         67/6625         2       1/8       0      2/0/0/0   function (s1, s2) { return s1.strengthValue < s2.stre
     addConstraint#EVo2Xv        33      67/705927         67/2755         2      4/10       0      4/0/2/0   function (c) { this.constraints.add(c); }
        satisfy#A7Z1GK          241      693/508400       693/508400       3       0/0      67      2/2/0/0   function (mark) { this.chooseMethod(mark); if (!this.
      recalculate#BFdxSK        194      113/503881       113/503881       2       0/0       0     17/2/4/0   function () { var ihn = this.input(), out = this.outp
  removePropagateFrom#DUqg5Z    509     12517/400519     12517/400519      3       0/0      101    39/5/19/0  function (out) { out.determinedBy = null; out.walkStr
     chooseMethod#EmCrCd        550     1472/399722      1472/399722       4       0/0      302    32/1/5/0   function (mark) { if (this.v1.mark == mark) { this.di
      markInputs#Bt3d5o          36      299/400794       299/299901       3       1/1       1      1/1/1/0   function (mark) { this.input().mark = mark; }
        output#DWTxXW            15      67/336927        67/333040        2       1/1       0      1/0/0/0   function () { return this.myOutput; }
        newMark#DnukEw           26      67/310927        67/197170        2      8/10       0      1/1/0/0   function () { return ++this.currentMark; }
     addConstraint#BL4Fyw        33      67/306927         67/1489         2       1/1       0      4/0/2/0   function (c) { this.v.add(c); }
       makePlan#CwbrZK          273     1469/305438      1469/610876       2       0/0       0     27/4/16/0  function (sources) { var mark = this.newMark(); var p
      Constraint#AN1q13          15      319/305848        319/101         2      14/24     174     0/1/0/0   function Constraint(strength) { this.strength = stren
     addConstraint#AXuot7        47      300/305794       300/10138        3      14/24     101     3/1/2/0   function () { this.addToGraph(); planner.incrementalA
    incrementalAdd#AfRCV0        91      201/305873        201/3692        2      12/18      0      2/1/1/0   function (c) { var mark = this.newMark(); var overrid
       Variable#DRKHYr          122      101/302893       101/302893       2       0/0       0      1/8/1/0   function Variable(name, initialValue) { this.value = 
      inputsKnown#CXx5Vd         67      134/301860       134/301860       2       0/0       0      3/0/1/0   function (mark) { var i = this.input(); return i.mark
      recalculate#CMNQ9a        152      106/299888       106/299888       2       1/1       0     30/3/7/0   function () { var ihn = this.input(), out = this.outp
        remove#B0QTYU           142     1185/205753       1185/2482        2       2/2       0      6/0/1/0   function (elm) { var index = 0, skipped = 0; for (var
    markUnsatisfied#BRrDiL       32      848/200380       848/193746       4       1/1      336     1/0/0/0   function () { this.direction = Direction.NONE; }
      addToGraph#BFaSkU          86      353/199741       353/97149        3       2/3      101    11/0/6/0   function () { this.v1.addConstraint(this); this.v2.ad
   BinaryConstraint#AiYUrn      127      174/199892         174/73         2       2/4       0      6/5/4/0   function BinaryConstraint(var1, var2, strength) { Bin
        execute#AkCU8K           3       64/139930        64/139930        2       0/0       0      0/0/0/0   function () { // Edit constraints do nothing }
      isSatisfied#CPIBWT         15      301/134694       301/125878       3      6/12      101     1/0/0/0   function () { return this.satisfied; }
     chooseMethod#CHIPoh         93     4390/105006      4390/105006       6       0/0     1504     8/0/1/0   function (mark) { this.satisfied = (this.myOutput.mar
      addToGraph#BaFEGQ          42     1883/104712      1883/104712       5       0/0      703     6/0/3/0   function () { this.myOutput.addConstraint(this); this
      recalculate#AUYZp5        114     2154/104441      2154/104441       5       0/0      703     6/2/1/0   function () { this.myOutput.walkStrength = this.stren
    UnaryConstraint#AyJC8w      101      441/105927         441/73         2      9/18      375     6/3/4/0   function UnaryConstraint(v, strength) { UnaryConstrai
      markInputs#CKYAeP          3       64/105930        64/105930        2       0/0       0      0/0/0/0   function (mark) { // has no inputs }
        isInput#Bzw1mn           3       64/100930         64/98881        2       1/1       0      0/0/0/0   function () { return false; }
    StayConstraint#EJitEM        75      67/100927         67/2500         2       1/4       0      8/3/5/0   function StayConstraint(v, str) { StayConstraint.supe
      markInputs#BKEMak         122      101/100893       101/100893       2       0/0       0      7/3/2/0   function (mark) { ScaleConstraint.superConstructor.pr
        execute#BG8Smc           3       64/100930         64/1320         2       1/4       0      0/0/0/0   function () { // Stay constraints do nothing }
       chainTest#BRCzIm         326     12700/98198     12700/8817300      3       0/0       0     40/3/26/0  function chainTest(n) { planner = new Planner(); var 
      addToGraph#Ay1DPa         131      103/99891        103/99891        2       0/0       0     27/0/13/0  function () { ScaleConstraint.superConstructor.protot
    ScaleConstraint#B4nxgu      125      102/99892        102/99892        2       0/0       0      9/4/5/0   function ScaleConstraint(src, scale, offset, dest, st
  EqualityConstraint#DhTXTS      81       67/99927         67/2701         2       1/2       0     20/6/8/0   function EqualityConstraint(var1, var2, strength) { E
    projectionTest#EMOLLI       545     12078/97900      12078/886780      3       0/0       0    127/10/79/0 function projectionTest(n) { planner = new Planner();
        change#C6ERan           154      3661/36301       3661/71761       3       1/2       0     28/2/17/0  function change(v, newValue) { var edit = new EditCon
        isInput#AqNT7n           3        64/9930          64/5041         2       1/1       0      0/0/0/0   function () { return true; }
    markUnsatisfied#Bzjx03       15       300/5794         300/1907        3       1/1      101     0/0/0/0   function () { this.satisfied = false; }
           #DenAe5              193       106/4889         106/4889        2       0/0       0     13/1/8/0   function (constraints) { var sources = new OrderedCol
      inputsKnown#AqNT7n         3        64/4930          64/4930         2       0/0       0      0/0/0/0   function () { return true; }
    EditConstraint#DUrVIr        75       369/4927         369/1752        2      5/12       0      7/1/5/0   function EditConstraint(v, str) { EditConstraint.supe
         Plan#B5ZGol             36       19/4974            19/0          1       1/1       0      0/0/0/0   function Plan() { this.v = new OrderedCollection(); }
   incrementalRemove#DcbNld     261       108/3887        108/201201       2       0/0       0     29/3/10/0  function (c) { var out = c.output(); c.markUnsatisfie
    removeFromGraph#EBtMK9       54       67/3927          67/2070         2       1/1       0     12/2/3/0   function () { if (this.myOutput != null) this.myOutpu
   destroyConstraint#B8OrJM      73       67/3927           67/296         2      5/10       0      3/0/1/0   function () { if (this.isSatisfied()) planner.increme
   removeConstraint#CvIMm2       61       66/3927            66/0          1       2/2       0      0/0/0/0   function (c) { this.constraints.remove(c); if (this.d
      nextWeaker#ATSwLS         173       106/3887          106/0          1       1/1       0      0/0/0/0   function () { switch (this.strengthValue) { case 0: r
        Planner#AduH5W           19       42/1951            42/0          1       1/4       0      0/0/0/0   function Planner() { this.currentMark = 0; }
        jscRun#DUxbew            15        67/927           67/927         2       0/0       0      0/0/1/0   function jscRun() { deltaBlue(); }
       deltaBlue#DNE2LT          33        66/927            66/0          1       1/1       0      0/0/0/0   function deltaBlue() { chainTest(100); projectionTest
       <global>#EnIUXZ          120        906/0            906/0          1       0/0       0      0/0/0/0   load("/Volumes/Data/pizlo/primary/Internal/Tools/V8Ha
       Inheriter#EBoivL          10         0/0              0/0           0       0/0       0        N/A     function Inheriter() { }
     inheritsFrom#AGNDON         67         0/0              0/0           0       0/0       0        N/A     function (shuper) { function Inheriter() { } Inherite
       <global>#AOJHdh           6          0/0              0/0           0       0/0       0        N/A     function jscSetUp() { } function jscTearDown() { } fu
    BenchmarkSuite#Dk0K1c        69         0/0              0/0           0       0/0       0        N/A     function BenchmarkSuite(name, reference, benchmarks) 
       Benchmark#BkgIav          74         0/0              0/0           0       0/0       0        N/A     function Benchmark(name, run, setup, tearDown) { this
       <global>#EAxWiA          2016        0/0              0/0           0       0/0       0        N/A     // Copyright 2008 the V8 project authors. All rights 
           #AIjJVG               15         0/0              0/0           0       0/0       0        N/A     function () { var seed = 49734321; return function() 
       <global>#Ac5Ih0          295         0/0              0/0           0       0/0       0        N/A     // Copyright 2008 the V8 project authors. All rights 
       Strength#BVqzBD           28         0/0              0/0           1       0/0       0      0/0/0/0   function Strength(strengthValue, name) { this.strengt

[Geoffrey Garen]

Comment on attachment 194401 [details]
the patch

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

What do we do with these numbers? Higher is better, but what we really want to know is how many calls/gets/etc. did we fail to optimize, and we can only know that with a number where lower is better, or if we display a total.

> Source/JavaScriptCore/profiler/ProfilerCompilation.h:61
> +    void noticeMiscInline() { m_numMiscInlines++; }

What's this for? It's unused. I just spent five minutes trying to figure out why the "M" column was always zero. Why do you torture me?

> Tools/Scripts/display-profiler-output:537
> +        print(" " + center("Recent Opts", recentOptsCols))

What does "Recent" mean here? Is it the last compilation? If so, can we call it "Last Opts"?

[Filip Pizlo]

(In reply to comment #3)
> (From update of attachment 194401 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=194401&action=review
> 
> What do we do with these numbers? Higher is better, but what we really want to know is how many calls/gets/etc. did we fail to optimize, and we can only know that with a number where lower is better, or if we display a total.
> 
> > Source/JavaScriptCore/profiler/ProfilerCompilation.h:61
> > +    void noticeMiscInline() { m_numMiscInlines++; }
> 
> What's this for? It's unused. I just spent five minutes trying to figure out why the "M" column was always zero. Why do you torture me?

:-(  Sorry about that.  I wanted to use it as a catch-all for weird things like the String.prototype.valueOf inlining.  But then I forgot to implement it.  It seemed to be good to have a catch-all for those because I thought we had a lot of them.

But now I think it's just dumb.  I'll apply the YAGNI rule and kill the misc thingy.

> 
> > Tools/Scripts/display-profiler-output:537
> > +        print(" " + center("Recent Opts", recentOptsCols))
> 
> What does "Recent" mean here? Is it the last compilation? If so, can we call it "Last Opts"?

ggaren++, I like that better.

[Filip Pizlo]

(In reply to comment #3)
> (From update of attachment 194401 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=194401&action=review
> 
> What do we do with these numbers? Higher is better, but what we really want to know is how many calls/gets/etc. did we fail to optimize, and we can only know that with a number where lower is better, or if we display a total.

I like to do the following:

Baseline JSC:
jsc -p thingy.profile thingy.js

Modified JSC:
jsc -p thingy.profile thingy.js

And then compare:

Baseline JSC:
echo "f" | Tools/Scripts/display-profiler-output > thingy.full

Modified JSC:
echo "f" | Tools/Scripts/display-profiler-output > thingy.full

And then the goodness:

diff -u /path/to/baseline/thingy.full /path/to/modified/thingy.full

I've used this for exits in the past and it's wonderful.  Now I'm using it for inlines.

The downside of counting "failures to inline" is that there are two of them: ForceOSRExit and the slow path version that does matching and/or makes calls.  The downside of counting them is that it would clutter the "full" display.

I think it would be cool to add the totals at some point, but I just wanted to have the basic thing first so that I could do my evil diff trick for seeing why my patch was slowing things down.

> 
> > Source/JavaScriptCore/profiler/ProfilerCompilation.h:61
> > +    void noticeMiscInline() { m_numMiscInlines++; }
> 
> What's this for? It's unused. I just spent five minutes trying to figure out why the "M" column was always zero. Why do you torture me?
> 
> > Tools/Scripts/display-profiler-output:537
> > +        print(" " + center("Recent Opts", recentOptsCols))
> 
> What does "Recent" mean here? Is it the last compilation? If so, can we call it "Last Opts"?

[Filip Pizlo]

Landed in http://trac.webkit.org/changeset/146548