Skip to content

Commit ecc332f

Browse files
Scala 2 forwardport: -Yprofile-trace (#19897)
* 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`
1 parent 276d0a3 commit ecc332f

File tree

18 files changed

+835
-78
lines changed

18 files changed

+835
-78
lines changed

Diff for: compiler/src/dotty/tools/dotc/Compiler.scala

+4-1
Original file line numberDiff line numberDiff line change
@@ -152,7 +152,10 @@ class Compiler {
152152
List(new GenBCode) :: // Generate JVM bytecode
153153
Nil
154154

155-
var runId: Int = 1
155+
// TODO: Initially 0, so that the first nextRunId call would return InitialRunId == 1
156+
// Changing the initial runId from 1 to 0 makes the scala2-library-bootstrap fail to compile,
157+
// when the underlying issue is fixed, please update dotc.profiler.RealProfiler.chromeTrace logic
158+
private var runId: Int = 1
156159
def nextRunId: Int = {
157160
runId += 1; runId
158161
}

Diff for: compiler/src/dotty/tools/dotc/Run.scala

+3-4
Original file line numberDiff line numberDiff line change
@@ -339,10 +339,9 @@ class Run(comp: Compiler, ictx: Context) extends ImplicitRunInfo with Constraint
339339
if phaseWillRun then
340340
Stats.trackTime(s"phase time ms/$phase") {
341341
val start = System.currentTimeMillis
342-
val profileBefore = profiler.beforePhase(phase)
343-
try units = phase.runOn(units)
344-
catch case _: InterruptedException => cancelInterrupted()
345-
profiler.afterPhase(phase, profileBefore)
342+
profiler.onPhase(phase):
343+
try units = phase.runOn(units)
344+
catch case _: InterruptedException => cancelInterrupted()
346345
if (ctx.settings.Xprint.value.containsPhase(phase))
347346
for (unit <- units)
348347
def printCtx(unit: CompilationUnit) = phase.printingContext(

Diff for: compiler/src/dotty/tools/dotc/config/ScalaSettings.scala

+4-6
Original file line numberDiff line numberDiff line change
@@ -441,12 +441,10 @@ private sealed trait YSettings:
441441
val YlegacyLazyVals: Setting[Boolean] = BooleanSetting(ForkSetting, "Ylegacy-lazy-vals", "Use legacy (pre 3.3.0) implementation of lazy vals.")
442442
val YcompileScala2Library: Setting[Boolean] = BooleanSetting(ForkSetting, "Ycompile-scala2-library", "Used when compiling the Scala 2 standard library.")
443443
val YprofileEnabled: Setting[Boolean] = BooleanSetting(ForkSetting, "Yprofile-enabled", "Enable profiling.")
444-
val YprofileDestination: Setting[String] = StringSetting(ForkSetting, "Yprofile-destination", "file", "Where to send profiling output - specify a file, default is to the console.", "")
445-
//.withPostSetHook( _ => YprofileEnabled.value = true )
446-
val YprofileExternalTool: Setting[List[String]] = PhasesSetting(ForkSetting, "Yprofile-external-tool", "Enable profiling for a phase using an external tool hook. Generally only useful for a single phase.", "typer")
447-
//.withPostSetHook( _ => YprofileEnabled.value = true )
448-
val YprofileRunGcBetweenPhases: Setting[List[String]] = PhasesSetting(ForkSetting, "Yprofile-run-gc", "Run a GC between phases - this allows heap size to be accurate at the expense of more time. Specify a list of phases, or *", "_")
449-
//.withPostSetHook( _ => YprofileEnabled.value = true )
444+
val YprofileDestination: Setting[String] = StringSetting(ForkSetting, "Yprofile-destination", "file", "Where to send profiling output - specify a file, default is to the console.", "", depends = List(YprofileEnabled -> true))
445+
val YprofileExternalTool: Setting[List[String]] = PhasesSetting(ForkSetting, "Yprofile-external-tool", "Enable profiling for a phase using an external tool hook. Generally only useful for a single phase.", "typer", depends = List(YprofileEnabled -> true))
446+
val YprofileRunGcBetweenPhases: Setting[List[String]] = PhasesSetting(ForkSetting, "Yprofile-run-gc", "Run a GC between phases - this allows heap size to be accurate at the expense of more time. Specify a list of phases, or *", "_", depends = List(YprofileEnabled -> true))
447+
val YprofileTrace: Setting[String] = StringSetting(ForkSetting, "Yprofile-trace", "file", s"Capture trace of compilation in JSON Chrome Trace format to the specified file. This option requires ${YprofileEnabled.name}. The output file can be visualized using https://ui.perfetto.dev/.", "", depends = List(YprofileEnabled -> true))
450448

451449
val YbestEffort: Setting[Boolean] = BooleanSetting(ForkSetting, "Ybest-effort", "Enable best-effort compilation attempting to produce betasty to the META-INF/best-effort directory, regardless of errors, as part of the pickler phase.")
452450
val YwithBestEffortTasty: Setting[Boolean] = BooleanSetting(ForkSetting, "Ywith-best-effort-tasty", "Allow to compile using best-effort tasty files. If such file is used, the compiler will stop after the pickler phase.")

Diff for: compiler/src/dotty/tools/dotc/config/Settings.scala

+10-5
Original file line numberDiff line numberDiff line change
@@ -73,6 +73,11 @@ object Settings:
7373
def validateSettingString(name: String): Unit =
7474
assert(settingCharacters.matches(name), s"Setting string $name contains invalid characters")
7575

76+
/** List of setting-value pairs that are required for another setting to be valid.
77+
* For example, `s = Setting(..., depends = List(YprofileEnabled -> true))`
78+
* means that `s` requires `YprofileEnabled` to be set to `true`.
79+
*/
80+
type SettingDependencies = List[(Setting[?], Any)]
7681

7782
case class Setting[T: ClassTag] private[Settings] (
7883
category: SettingCategory,
@@ -83,7 +88,7 @@ object Settings:
8388
choices: Option[Seq[?]] = None,
8489
prefix: Option[String] = None,
8590
aliases: List[String] = Nil,
86-
depends: List[(Setting[?], Any)] = Nil,
91+
depends: SettingDependencies = Nil,
8792
ignoreInvalidArgs: Boolean = false,
8893
preferPrevious: Boolean = false,
8994
propertyClass: Option[Class[?]] = None,
@@ -385,8 +390,8 @@ object Settings:
385390
def BooleanSetting(category: SettingCategory, name: String, descr: String, initialValue: Boolean = false, aliases: List[String] = Nil, preferPrevious: Boolean = false, deprecation: Option[Deprecation] = None, ignoreInvalidArgs: Boolean = false): Setting[Boolean] =
386391
publish(Setting(category, prependName(name), descr, initialValue, aliases = aliases, preferPrevious = preferPrevious, deprecation = deprecation, ignoreInvalidArgs = ignoreInvalidArgs))
387392

388-
def StringSetting(category: SettingCategory, name: String, helpArg: String, descr: String, default: String, aliases: List[String] = Nil, deprecation: Option[Deprecation] = None): Setting[String] =
389-
publish(Setting(category, prependName(name), descr, default, helpArg, aliases = aliases, deprecation = deprecation))
393+
def StringSetting(category: SettingCategory, name: String, helpArg: String, descr: String, default: String, aliases: List[String] = Nil, deprecation: Option[Deprecation] = None, depends: SettingDependencies = Nil): Setting[String] =
394+
publish(Setting(category, prependName(name), descr, default, helpArg, aliases = aliases, deprecation = deprecation, depends = depends))
390395

391396
def ChoiceSetting(category: SettingCategory, name: String, helpArg: String, descr: String, choices: List[String], default: String, aliases: List[String] = Nil, legacyArgs: Boolean = false, deprecation: Option[Deprecation] = None): Setting[String] =
392397
publish(Setting(category, prependName(name), descr, default, helpArg, Some(choices), aliases = aliases, legacyArgs = legacyArgs, deprecation = deprecation))
@@ -412,8 +417,8 @@ object Settings:
412417
def PathSetting(category: SettingCategory, name: String, descr: String, default: String, aliases: List[String] = Nil, deprecation: Option[Deprecation] = None): Setting[String] =
413418
publish(Setting(category, prependName(name), descr, default, aliases = aliases, deprecation = deprecation))
414419

415-
def PhasesSetting(category: SettingCategory, name: String, descr: String, default: String = "", aliases: List[String] = Nil, deprecation: Option[Deprecation] = None): Setting[List[String]] =
416-
publish(Setting(category, prependName(name), descr, if (default.isEmpty) Nil else List(default), aliases = aliases, deprecation = deprecation))
420+
def PhasesSetting(category: SettingCategory, name: String, descr: String, default: String = "", aliases: List[String] = Nil, deprecation: Option[Deprecation] = None, depends: SettingDependencies = Nil): Setting[List[String]] =
421+
publish(Setting(category, prependName(name), descr, if (default.isEmpty) Nil else List(default), aliases = aliases, deprecation = deprecation, depends = depends))
417422

418423
def PrefixSetting(category: SettingCategory, name0: String, descr: String, deprecation: Option[Deprecation] = None): Setting[List[String]] =
419424
val name = prependName(name0)

Diff for: compiler/src/dotty/tools/dotc/core/Contexts.scala

+1
Original file line numberDiff line numberDiff line change
@@ -769,6 +769,7 @@ object Contexts {
769769
.updated(settingsStateLoc, settingsGroup.defaultState)
770770
.updated(notNullInfosLoc, Nil)
771771
.updated(compilationUnitLoc, NoCompilationUnit)
772+
.updated(profilerLoc, Profiler.NoOp)
772773
c._searchHistory = new SearchRoot
773774
c._gadtState = GadtState(GadtConstraint.empty)
774775
c

Diff for: compiler/src/dotty/tools/dotc/core/Phases.scala

+1-1
Original file line numberDiff line numberDiff line change
@@ -370,7 +370,7 @@ object Phases {
370370
// Test that we are in a state where we need to check if the phase should be skipped for a java file,
371371
// this prevents checking the expensive `unit.typedAsJava` unnecessarily.
372372
val doCheckJava = skipIfJava && !isAfterLastJavaPhase
373-
for unit <- units do
373+
for unit <- units do ctx.profiler.onUnit(this, unit):
374374
given unitCtx: Context = runCtx.fresh.setPhase(this.start).setCompilationUnit(unit).withRootImports
375375
if ctx.run.enterUnit(unit) then
376376
try

Diff for: compiler/src/dotty/tools/dotc/core/SymbolLoaders.scala

+10-2
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ import java.nio.channels.ClosedByInterruptException
88
import scala.util.control.NonFatal
99

1010
import dotty.tools.dotc.classpath.FileUtils.{hasTastyExtension, hasBetastyExtension}
11-
import dotty.tools.io.{ ClassPath, ClassRepresentation, AbstractFile }
11+
import dotty.tools.io.{ ClassPath, ClassRepresentation, AbstractFile, NoAbstractFile }
1212
import dotty.tools.backend.jvm.DottyBackendInterface.symExtensions
1313

1414
import Contexts.*, Symbols.*, Flags.*, SymDenotations.*, Types.*, Scopes.*, Names.*
@@ -333,7 +333,15 @@ abstract class SymbolLoader extends LazyType { self =>
333333
def description(using Context): String = s"proxy to ${self.description}"
334334
}
335335

336-
override def complete(root: SymDenotation)(using Context): Unit = {
336+
private inline def profileCompletion[T](root: SymDenotation)(inline body: T)(using Context): T = {
337+
val sym = root.symbol
338+
def associatedFile = root.symbol.associatedFile match
339+
case file: AbstractFile => file
340+
case _ => NoAbstractFile
341+
ctx.profiler.onCompletion(sym, associatedFile)(body)
342+
}
343+
344+
override def complete(root: SymDenotation)(using Context): Unit = profileCompletion(root) {
337345
def signalError(ex: Exception): Unit = {
338346
if (ctx.debug) ex.printStackTrace()
339347
val msg = ex.getMessage()
+190
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,190 @@
1+
// Scala 2 compiler backport of https://github.com/scala/scala/pull/7364
2+
/*
3+
* Scala (https://www.scala-lang.org)
4+
*
5+
* Copyright EPFL and Lightbend, Inc.
6+
*
7+
* Licensed under Apache License 2.0
8+
* (http://www.apache.org/licenses/LICENSE-2.0).
9+
*
10+
* See the NOTICE file distributed with this work for
11+
* additional information regarding copyright ownership.
12+
*/
13+
14+
package dotty.tools.dotc.profile
15+
16+
import scala.language.unsafeNulls
17+
18+
import java.io.Closeable
19+
import java.lang.management.ManagementFactory
20+
import java.nio.file.{Files, Path}
21+
import java.util
22+
import java.util.concurrent.TimeUnit
23+
24+
import scala.collection.mutable
25+
26+
object ChromeTrace {
27+
private object EventType {
28+
final val Start = "B"
29+
final val Instant = "I"
30+
final val End = "E"
31+
final val Complete = "X"
32+
33+
final val Counter = "C"
34+
35+
final val AsyncStart = "b"
36+
final val AsyncInstant = "n"
37+
final val AsyncEnd = "e"
38+
}
39+
}
40+
41+
/** Allows writing a subset of captrue traces based on https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#
42+
* Can be visualized using https://ui.perfetto.dev/, Chrome's about://tracing (outdated) or the tooling in https://www.google.com.au/search?q=catapult+tracing&oq=catapult+tracing+&aqs=chrome..69i57.3974j0j4&sourceid=chrome&ie=UTF-8 */
43+
final class ChromeTrace(f: Path) extends Closeable {
44+
import ChromeTrace.EventType
45+
private val traceWriter = FileUtils.newAsyncBufferedWriter(f)
46+
private val context = mutable.Stack[JsonContext](TopContext)
47+
private val tidCache = new ThreadLocal[String]() {
48+
override def initialValue(): String = "%05d".format(Thread.currentThread().getId())
49+
}
50+
objStart()
51+
fld("traceEvents")
52+
context.push(ValueContext)
53+
arrStart()
54+
traceWriter.newLine()
55+
56+
private val pid = ManagementFactory.getRuntimeMXBean().getName().replaceAll("@.*", "")
57+
58+
override def close(): Unit = {
59+
arrEnd()
60+
objEnd()
61+
context.pop()
62+
tidCache.remove()
63+
traceWriter.close()
64+
}
65+
66+
def traceDurationEvent(name: String, startNanos: Long, durationNanos: Long, tid: String = this.tid(), pidSuffix: String = ""): Unit = {
67+
val durationMicros = nanosToMicros(durationNanos)
68+
val startMicros = nanosToMicros(startNanos)
69+
objStart()
70+
str("cat", "scalac")
71+
str("name", name)
72+
str("ph", EventType.Complete)
73+
str("tid", tid)
74+
writePid(pidSuffix)
75+
lng("ts", startMicros)
76+
lng("dur", durationMicros)
77+
objEnd()
78+
traceWriter.newLine()
79+
}
80+
81+
private def writePid(pidSuffix: String) = {
82+
if (pidSuffix == "")
83+
str("pid", pid)
84+
else
85+
str2("pid", pid, "-", pidSuffix)
86+
}
87+
88+
def traceCounterEvent(name: String, counterName: String, count: Long, processWide: Boolean): Unit = {
89+
objStart()
90+
str("cat", "scalac")
91+
str("name", name)
92+
str("ph", EventType.Counter)
93+
str("tid", tid())
94+
writePid(pidSuffix = if (processWide) "" else tid())
95+
lng("ts", microTime())
96+
fld("args")
97+
objStart()
98+
lng(counterName, count)
99+
objEnd()
100+
objEnd()
101+
traceWriter.newLine()
102+
}
103+
104+
def traceDurationEventStart(cat: String, name: String, colour: String = "", pidSuffix: String = tid()): Unit = traceDurationEventStartEnd(EventType.Start, cat, name, colour, pidSuffix)
105+
def traceDurationEventEnd(cat: String, name: String, colour: String = "", pidSuffix: String = tid()): Unit = traceDurationEventStartEnd(EventType.End, cat, name, colour, pidSuffix)
106+
107+
private def traceDurationEventStartEnd(eventType: String, cat: String, name: String, colour: String, pidSuffix: String = ""): Unit = {
108+
objStart()
109+
str("cat", cat)
110+
str("name", name)
111+
str("ph", eventType)
112+
writePid(pidSuffix)
113+
str("tid", tid())
114+
lng("ts", microTime())
115+
if (colour != "") {
116+
str("cname", colour)
117+
}
118+
objEnd()
119+
traceWriter.newLine()
120+
}
121+
122+
private def tid(): String = tidCache.get()
123+
124+
private def nanosToMicros(t: Long): Long = TimeUnit.NANOSECONDS.toMicros(t)
125+
126+
private def microTime(): Long = nanosToMicros(System.nanoTime())
127+
128+
private sealed abstract class JsonContext
129+
private case class ArrayContext(var first: Boolean) extends JsonContext
130+
private case class ObjectContext(var first: Boolean) extends JsonContext
131+
private case object ValueContext extends JsonContext
132+
private case object TopContext extends JsonContext
133+
134+
private def str(name: String, value: String): Unit = {
135+
fld(name)
136+
traceWriter.write("\"")
137+
traceWriter.write(value) // This assumes no escaping is needed
138+
traceWriter.write("\"")
139+
}
140+
private def str2(name: String, value: String, valueContinued1: String, valueContinued2: String): Unit = {
141+
fld(name)
142+
traceWriter.write("\"")
143+
traceWriter.write(value) // This assumes no escaping is needed
144+
traceWriter.write(valueContinued1) // This assumes no escaping is needed
145+
traceWriter.write(valueContinued2) // This assumes no escaping is needed
146+
traceWriter.write("\"")
147+
}
148+
private def lng(name: String, value: Long): Unit = {
149+
fld(name)
150+
traceWriter.write(String.valueOf(value))
151+
traceWriter.write("")
152+
}
153+
private def objStart(): Unit = {
154+
context.top match {
155+
case ac @ ArrayContext(first) =>
156+
if (first) ac.first = false
157+
else traceWriter.write(",")
158+
case _ =>
159+
}
160+
context.push(ObjectContext(true))
161+
traceWriter.write("{")
162+
}
163+
private def objEnd(): Unit = {
164+
traceWriter.write("}")
165+
context.pop()
166+
}
167+
private def arrStart(): Unit = {
168+
traceWriter.write("[")
169+
context.push(ArrayContext(true))
170+
}
171+
private def arrEnd(): Unit = {
172+
traceWriter.write("]")
173+
context.pop()
174+
}
175+
176+
private def fld(name: String) = {
177+
val topContext = context.top
178+
topContext match {
179+
case oc @ ObjectContext(first) =>
180+
if (first) oc.first = false
181+
else traceWriter.write(",")
182+
case context =>
183+
throw new IllegalStateException("Wrong context: " + context)
184+
}
185+
traceWriter.write("\"")
186+
traceWriter.write(name)
187+
traceWriter.write("\"")
188+
traceWriter.write(":")
189+
}
190+
}

0 commit comments

Comments
 (0)