Capture contextual typer timings suitable for flamegraphs

[retronym]

• Time spent completing lazy types is excluded from the callsite,
  and instead attributed to the symbol being completed itself.
• The top-most implicit search or macro expansion is included in
  the trace

package p1

import scala.reflect.macros.blackbox._
import language.experimental._

object Macro {
  def impl(c: Context): c.Tree = {
    import c.universe._
    println(rootMirror.staticClass("p1.Base").knownDirectSubclasses)
    q"()"
  }
  def p1_Base_knownDirectSubclasses: Unit = macro impl
}

class Test1 {
  Sleep.sleep(100)
  def twoHundred() {
    Sleep.sleep(200)
  }
  def fast() {
    "".isEmpty
  }
  def stillFast() {
    new Test3
  }
  val slowVal = Sleep.sleep(140)
  def slowDefSlowVal = {
    Sleep.sleep(140)
    val slowValNested = Sleep.sleep(140)
  }
  def fooCall(t: Test3) = t.foo
}

class Test3 extends Test2(Sleep.sleep(100)) {
  def foo = Sleep.sleep(300)
}
class Test2[T](a: T)

Gives:

⚡ cat /tmp/output.csv
<root>;java;lang;invoke 6784973
<root>;scala;Boolean 1008832
<root>;<empty>;Test3;<init> 3968070
<root>;scala;AnyVal 545566
<root>;<empty>;Test1 41991858
<root>;scala;reflect;macros 3394111
<root>;<empty>;Test1;stillFast 44014771
<root>;<empty> 3888809
<root>;<empty>;Test1;slowDefSlowVal;slowValNested;<macro>;Sleep.sleep 145958765
<root>;scala;DeprecatedPredef 1905347
<root>;scala;reflect;macros;internal 1038672
<root>;<empty>;Test1;twoHundred 2229225
<root>;<empty>;Test2;a 140655
<root>;<empty>;Test1;slowVal ;<macro>;Sleep.sleep 142835436
<root>;<empty>;<local <empty>>;<macro>;Sleep.sleep 103792019
<root>;<empty>;Test1;slowVal 488540
<root>;<empty>;Test1;twoHundred;<macro>;Sleep.sleep 204254878
<root>;<empty>;Test2;<init>;a 138838
<root>;<empty>;Sleep 5413257
<root>;java;util;stream 3461340
<root>;<empty>;Test1;fooCall;t 434245
<root>;<empty>;Test1;slowVal  517689
<root>;<empty>;Test3;<init>;<macro>;Sleep.sleep 103095814
<root>;<empty>;Test3 6626318
<root>;java;lang;CharSequence 1181685
<root>;<empty>;Test2 4495052
<root>;<empty>;Test3;foo 141093
<root>;scala;collection;immutable 6981213
<root>;<empty>;Test3;foo;<macro>;Sleep.sleep 307391221
<root>;<empty>;Test2;<init> 1416591
<root>;scala;Unit 849716
<root>;scala;reflect;macros;package 1492276
<root>;<empty>;Test1;<local Test1>;<macro>;Sleep.sleep 207086274
<root>;scala;Int 3794993
<root>;<empty>;Test1;slowDefSlowVal;<macro>;Sleep.sleep 145070640
<root>;scala;Predef 13958827
<root>;<empty>;Test1;slowDefSlowVal;slowValNested 186048
<root>;<empty>;<local <empty>>;<macro>;Sleep.sleep 106121967
<root>;<empty>;Test1;<init> 19296574
<root>;scala;LowPriorityImplicits 2508560
<root>;<empty>;Test1;fooCall 1268531
<root>;<empty>;Test1;fast 2643270
<root>;<empty>;Test1;slowDefSlowVal 156368

Which renders to:

/code/FlameGraph/flamegraph.pl /tmp/output.csv > output.svg
/code/FlameGraph/flamegraph.pl --reverse /tmp/output.csv > output-reverse.svg

https://cdn.rawgit.com/retronym/672ca835fb5513003499ce6c68831219/raw/975adfa0a4d9bda45264002bf0e0206a03e2cbd4/output.svg
https://cdn.rawgit.com/retronym/01b6640a1ef5584add72f432735d540e/raw/89de5e8e32ad9a2dddf1dc3473c27546e770f8f8/output-reverse.svg

Larger examples (compiling the Scala library)

https://cdn.rawgit.com/retronym/03f98f844f661f9f085bde627e91d32f/raw/6244198cae0344419e6d2c78a17541a865fb6179/output.svg
https://cdn.rawgit.com/retronym/03f98f844f661f9f085bde627e91d32f/raw/6244198cae0344419e6d2c78a17541a865fb6179/output-reverse.svg

[retronym]

Superceded by #28