[WIP] Emit detailed compiler trace under -Yprofile

[retronym]

Suitable for viewing directly in chrome://tracing, or manipulation
with the underlying tooling at:

https://github.com/catapult-project/catapult/tree/master/tracing

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

TODO:

• Create a post-processing tool to generate collapsed stack flamegraph format suitable for https://github.com/brendangregg/FlameGraph (perhaps submitted to that project, Add stackcollapse for chrome trace event format brendangregg/FlameGraph#158 isn't sufficient)
• Create a post-processing tool to target https://speedscope.app/ format (or extend its partial support for importing Chrome Trace files to handle the start/end event we're using.
• Measure and minimize the overhead of enabling the trace
• Create a new -Y option to turn this on specifically, rather than just piggybacking on -Yprofile.

[retronym]

profile.trace file generated with this PR.

[retronym]

How to test this yourself:

Publish this PR locally

$ sbt
> set scala.build.ScriptCommands.enableOptimizer ++ scala.build.ScriptCommands.noDocs ++ ((baseVersionSuffix in Global := "SHA"):: Nil)
[info] Defining */*:baseVersionSuffix, {.}/compile:packageDoc::publishArtifact, {.}/compile:scalacOptions
[info] The new values will be used by */*:versionProperties, bootstrap/*:artifacts and 33 others.
[info] 	Run `last` for details.
[info] Reapplying settings...
[info] *** Welcome to the sbt build definition for Scala! ***
[info] Check README.md for more information.
> publishLocal

...
[info] 	published scala-compiler to /Users/jz/.ivy2/local/org.scala-lang/scala-compiler/2.12.8-bin-4c77697/jars/scala-compiler.jar
[info] 	published ivy to /Users/jz/.ivy2/local/org.scala-lang/scala-compiler/2.12.8-bin-4c77697/ivys/ivy.xml

Modify a project to add the compiler options and to depend on this version:

/code/guardian-frontend on master*
$ git diff head -U2
diff --git a/project/ProjectSettings.scala b/project/ProjectSettings.scala
index f8ffd13797..cf823f4443 100644
--- a/project/ProjectSettings.scala
+++ b/project/ProjectSettings.scala
@@ -26,5 +26,5 @@ object ProjectSettings {
     sources in (Compile,doc) := Seq.empty,
     doc in Compile := target.map(_ / "none").value,
-    scalaVersion := "2.12.7",
+    scalaVersion := "2.12.8-bin-4c77697",
     initialize := {
       val _ = initialize.value
@@ -36,4 +36,6 @@ object ProjectSettings {
       clean.all(allProjects)
     }.value
+  ) ++ Seq(Compile, Test).map(config =>
+    scalacOptions in config := List("-Yprofile-enabled", "-Yprofile-destination", target.value / config.toString + ".csv")
   )

Build

$ sbt -J-Xmx1G clean test:compile clean test:compile
...
Trace file: /Users/jz/code/guardian-frontend/sport/target/test.trace
[info] Done compiling.
Trace file: /Users/jz/code/guardian-frontend/applications/target/test.trace
[info] Done compiling.
[success] Total time: 65 s, completed 05/10/2018 2:19:11 PM

Sample .trace files

View in Chrome

Enter chrome://tracing, and open a .trace file.

Combine Trace Files (optional)

$ (echo '{"traceEvents": [ {"name": "process_name", "ph": "M", "pid": -1, "tid": 2347,"args": {"name": "dummy"}}'; (for f in $(find . -name '*.trace'); do cat $f | perl -pne 's/{"traceEvents": \[\n/,/' |  perl -pne 's/]}//'; done) | egrep -v '^,$'; echo ']}') > /tmp/combined.trace

Generates combined.trace.zip

[retronym]

I'm working on the post-processing tool https://github.com/retronym/chrome-trace-to-flamegraph

This tool should be able:

• Split traces that span a stop-the-world GC event into a pre- and post- span that exclude the time that the JVM was inactive.
• When a type completor starts: stop the in-progress span and pretend that the recursive frames of the completer where the base of the stack. When we pop out of the completion, re-start the stopped enclosing frame.
• output to a compressed Chrome Trace format, collapsing begin/end events into complete events for compression
  • maybe further compressing by symbolizing stack trace elements
• output Flamegraph collapsed stack format
• output speedscope format

[retronym]

I've made a bit of progress in the post-processing tool. Here's the latest output:

https://drive.google.com/drive/folders/1EJJb7Yy52gpu6wNjOgPfh39D4V2MOihC?usp=sharing

[retronym]

Moved to scala#7364