Emit detailed compiler trace under -Yprofile-trace by retronym · Pull Request #7364 · scala/scala

retronym · 2018-10-23T05:15:30Z

Suitable for viewing directly in chrome://tracing, or post processing
with https://github.com/retronym/chrome-trace-to-flamegraph

Co-Authored-By: Mike Skells mike.skells@talk21.com

Demo

Editing an SBT build to add these settings to each project.

def profileSettings = Seq(Compile, Test).map(config => scalacOptions in config := List("-Ycache-macro-class-loader:last-modified", "-Yprofile-trace")

Compiling the project will create:

$ find $PWD -name '*.trace' | xargs echo
/code/guardian-frontend/identity/target/compile.trace /code/guardian-frontend/identity/target/test.trace /code/guardian-frontend/archive/target/compile.trace /code/guardian-frontend/archive/target/test.trace /code/guardian-frontend/rss/target/compile.trace /code/guardian-frontend/admin/target/compile.trace /code/guardian-frontend/admin/target/test.trace /code/guardian-frontend/facia/target/compile.trace /code/guardian-frontend/facia/target/test.trace /code/guardian-frontend/sport/target/compile.trace /code/guardian-frontend/sport/target/test.trace /code/guardian-frontend/commercial/target/compile.trace /code/guardian-frontend/commercial/target/test.trace /code/guardian-frontend/common/target/compile.trace /code/guardian-frontend/common/target/test.trace /code/guardian-frontend/diagnostics/target/compile.trace /code/guardian-frontend/diagnostics/target/test.trace /code/guardian-frontend/applications/target/compile.trace /code/guardian-frontend/applications/target/test.trace /code/guardian-frontend/preview/target/compile.trace /code/guardian-frontend/preview/target/test.trace /code/guardian-frontend/article/target/compile.trace /code/guardian-frontend/article/target/test.trace /code/guardian-frontend/discussion/target/compile.trace /code/guardian-frontend/discussion/target/test.trace /code/guardian-frontend/facia-press/target/compile.trace /code/guardian-frontend/facia-press/target/test.trace /code/guardian-frontend/onward/target/compile.trace /code/guardian-frontend/onward/target/test.trace

These can be loaded individually into chrome://tracing in Chrome.

Post process to aggregate, split events when GC occurs or when lazy type completion occurs

$ git clone https://github.com/retronym/chrome-trace-to-flamegraph; cd chrome-trace-to-flamegraph; sbt
...
sbt:chrome-trace-to-flamegraph> runMain io.github.retronym.chrometraceflame.ChromeTraceFlame /code/guardian-frontend/identity/target/compile.trace /code/guardian-frontend/identity/target/test.trace /code/guardian-frontend/archive/target/compile.trace /code/guardian-frontend/archive/target/test.trace /code/guardian-frontend/rss/target/compile.trace /code/guardian-frontend/admin/target/compile.trace /code/guardian-frontend/admin/target/test.trace /code/guardian-frontend/facia/target/compile.trace /code/guardian-frontend/facia/target/test.trace /code/guardian-frontend/sport/target/compile.trace /code/guardian-frontend/sport/target/test.trace /code/guardian-frontend/commercial/target/compile.trace /code/guardian-frontend/commercial/target/test.trace /code/guardian-frontend/common/target/compile.trace /code/guardian-frontend/common/target/test.trace /code/guardian-frontend/diagnostics/target/compile.trace /code/guardian-frontend/diagnostics/target/test.trace /code/guardian-frontend/applications/target/compile.trace /code/guardian-frontend/applications/target/test.trace /code/guardian-frontend/preview/target/compile.trace /code/guardian-frontend/preview/target/test.trace /code/guardian-frontend/article/target/compile.trace /code/guardian-frontend/article/target/test.trace /code/guardian-frontend/discussion/target/compile.trace /code/guardian-frontend/discussion/target/test.trace /code/guardian-frontend/facia-press/target/compile.trace /code/guardian-frontend/facia-press/target/test.trace /code/guardian-frontend/onward/target/compile.trace /code/guardian-frontend/onward/target/test.trace
[info] Running io.github.retronym.chrometraceflame.ChromeTraceFlame /code/guardian-frontend/identity/target/compile.trace /code/guardian-frontend/identity/target/test.trace /code/guardian-frontend/archive/target/compile.trace /code/guardian-frontend/archive/target/test.trace /code/guardian-frontend/rss/target/compile.trace /code/guardian-frontend/admin/target/compile.trace /code/guardian-frontend/admin/target/test.trace /code/guardian-frontend/facia/target/compile.trace /code/guardian-frontend/facia/target/test.trace /code/guardian-frontend/sport/target/compile.trace /code/guardian-frontend/sport/target/test.trace /code/guardian-frontend/commercial/target/compile.trace /code/guardian-frontend/commercial/target/test.trace /code/guardian-frontend/common/target/compile.trace /code/guardian-frontend/common/target/test.trace /code/guardian-frontend/diagnostics/target/compile.trace /code/guardian-frontend/diagnostics/target/test.trace /code/guardian-frontend/applications/target/compile.trace /code/guardian-frontend/applications/target/test.trace /code/guardian-frontend/preview/target/compile.trace /code/guardian-frontend/preview/target/test.trace /code/guardian-frontend/article/target/compile.trace /code/guardian-frontend/article/target/test.trace /code/guardian-frontend/discussion/target/compile.trace /code/guardian-frontend/discussion/target/test.trace /code/guardian-frontend/facia-press/target/compile.trace /code/guardian-frontend/facia-press/target/test.trace /code/guardian-frontend/onward/target/compile.trace /code/guardian-frontend/onward/target/test.trace
[success] Total time: 4 s, completed 23/10/2018 5:03:58 PM
sbt:chrome-trace-to-flamegraph> [info] shutting down server
/code/chrome-trace-to-flamegraph on master*

$ ls -la /tmp/combined.*
-rw-r--r--  1 jz  wheel   5998325 Oct 23 17:03 /tmp/combined.csv
-rw-r--r--  1 jz  wheel  37307335 Oct 23 17:03 /tmp/combined.trace

combined.trace can be viewed in chrome:/tracing.

Generate flame graphs.

$ cat /tmp/combined.csv | /code/FlameGraph/flamegraph.pl --minwidth 2 --width 2000 - > /tmp/combined.svg
$ cat /tmp/combined.csv | /code/FlameGraph/flamegraph.pl --minwidth 2 --width 2000 --reverse - > /tmp/combined-reverse.svg

UPDATE

speedscope.app can now import the compile.trace file directly and render both the trace view (what happens over time) and the flamegraph view.

retronym · 2018-10-24T04:06:58Z

/rebuild

retronym · 2018-10-24T06:04:32Z

FTR, the OSGi test failure:

Failed
tools.test.osgi.reflection.basic.BasicReflectionTest.basicMirrorThroughOsgi

Failing for the past 2 builds (Since Failed#1225 )
Took 0.16 sec.
Error Message
java.lang.ClassNotFoundException: scala.reflect.api.TypeCreator cannot be found by PAXEXAM-PROBE-19e21849-47b6-4f7b-82af-e84a86fd7ff5_0.0.0
Stacktrace
sbt.ForkMain$ForkError: java.lang.ClassNotFoundException: scala.reflect.api.TypeCreator cannot be found by PAXEXAM-PROBE-19e21849-47b6-4f7b-82af-e84a86fd7ff5_0.0.0
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:439)
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:352)
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:344)
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)

Turned out to be a usage of import sun.security.action.GetPropertyAction in the newly added FileUtilities. Not sure what the causal chain was between that and the symptom.

Suitable for viewing directly in chrome://tracing, or post processing with https://github.com/retronym/chrome-trace-to-flamegraph Co-Authored-By: Mike Skells <mike.skells@talk21.com>

retronym · 2018-11-07T08:58:21Z

/cc @dragos

* Scala 2 tracing profiler backport from scala/scala#7364 extended with more Scala 3 idiomatic syntax based on inlined methods * Fixes the `context.profiler` which could have been `null`, now it's initially a NoOp Profiler * Check dependencies of `-Yprofile-enabled` dependent tasks, now we get an error if `-Yprofile-trace` is set without `-Yprofile-enabled`

* Scala 2 tracing profiler backport from scala/scala#7364 extended with more Scala 3 idiomatic syntax based on inlined methods * Fixes the `context.profiler` which could have been `null`, now it's initially a NoOp Profiler * Check dependencies of `-Yprofile-enabled` dependent tasks, now we get an error if `-Yprofile-trace` is set without `-Yprofile-enabled` [Cherry-picked ecc332f][modified]

* Scala 2 tracing profiler backport from scala/scala#7364 extended with more Scala 3 idiomatic syntax based on inlined methods * Fixes the `context.profiler` which could have been `null`, now it's initially a NoOp Profiler * Check dependencies of `-Yprofile-enabled` dependent tasks, now we get an error if `-Yprofile-trace` is set without `-Yprofile-enabled`

* Scala 2 tracing profiler backport from scala/scala#7364 extended with more Scala 3 idiomatic syntax based on inlined methods * Fixes the `context.profiler` which could have been `null`, now it's initially a NoOp Profiler * Check dependencies of `-Yprofile-enabled` dependent tasks, now we get an error if `-Yprofile-trace` is set without `-Yprofile-enabled` [Cherry-picked ecc332f][modified]

scala-jenkins added this to the 2.12.8 milestone Oct 23, 2018

retronym force-pushed the topic/statify-chrome-trace branch 2 times, most recently from 3c0f632 to 583c3ef Compare October 23, 2018 23:22

retronym mentioned this pull request Oct 24, 2018

[WIP] Emit detailed compiler trace under -Yprofile retronym/scala#28

Closed

4 tasks

retronym force-pushed the topic/statify-chrome-trace branch from 583c3ef to 38f7a85 Compare October 24, 2018 06:01

retronym force-pushed the topic/statify-chrome-trace branch 2 times, most recently from 59cdc98 to 3202908 Compare October 29, 2018 03:02

Emit detailed compiler trace under -Yprofile-trace

856c111

Suitable for viewing directly in chrome://tracing, or post processing with https://github.com/retronym/chrome-trace-to-flamegraph Co-Authored-By: Mike Skells <mike.skells@talk21.com>

retronym force-pushed the topic/statify-chrome-trace branch from 3202908 to 856c111 Compare October 31, 2018 05:18

adriaanm merged commit ae8133c into scala:2.12.x Oct 31, 2018

SethTisue added the release-notes worth highlighting in next release notes label Oct 31, 2018

SethTisue mentioned this pull request Nov 14, 2018

Scala 2.12.8 regression? sbt test failing (actionsProj sbt.compiler.EvalTest) scala/scala-dev#580

Closed

WojciechMazur mentioned this pull request Mar 7, 2024

Scala 2 forwardport: -Yprofile-trace scala/scala3#19897

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Emit detailed compiler trace under -Yprofile-trace#7364

Emit detailed compiler trace under -Yprofile-trace#7364
adriaanm merged 1 commit intoscala:2.12.xfrom
retronym:topic/statify-chrome-trace

retronym commented Oct 23, 2018 •

edited

Loading

Uh oh!

retronym commented Oct 24, 2018

Uh oh!

retronym commented Oct 24, 2018

Uh oh!

retronym commented Nov 7, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Conversation

retronym commented Oct 23, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Demo

UPDATE

Uh oh!

retronym commented Oct 24, 2018

Uh oh!

retronym commented Oct 24, 2018

Uh oh!

retronym commented Nov 7, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

retronym commented Oct 23, 2018 •

edited

Loading