Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Scala 2 forwardport: -Yprofile-trace #19897

Merged
merged 12 commits into from
Oct 22, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 4 additions & 1 deletion compiler/src/dotty/tools/dotc/Compiler.scala
Original file line number Diff line number Diff line change
Expand Up @@ -151,7 +151,10 @@ class Compiler {
List(new GenBCode) :: // Generate JVM bytecode
Nil

var runId: Int = 1
// TODO: Initially 0, so that the first nextRunId call would return InitialRunId == 1
// Changing the initial runId from 1 to 0 makes the scala2-library-bootstrap fail to compile,
// when the underlying issue is fixed, please update dotc.profiler.RealProfiler.chromeTrace logic
private var runId: Int = 1
def nextRunId: Int = {
runId += 1; runId
}
Expand Down
7 changes: 3 additions & 4 deletions compiler/src/dotty/tools/dotc/Run.scala
Original file line number Diff line number Diff line change
Expand Up @@ -339,10 +339,9 @@ class Run(comp: Compiler, ictx: Context) extends ImplicitRunInfo with Constraint
if phaseWillRun then
Stats.trackTime(s"phase time ms/$phase") {
val start = System.currentTimeMillis
val profileBefore = profiler.beforePhase(phase)
try units = phase.runOn(units)
catch case _: InterruptedException => cancelInterrupted()
profiler.afterPhase(phase, profileBefore)
profiler.onPhase(phase):
try units = phase.runOn(units)
catch case _: InterruptedException => cancelInterrupted()
if (ctx.settings.Xprint.value.containsPhase(phase))
for (unit <- units)
def printCtx(unit: CompilationUnit) = phase.printingContext(
Expand Down
10 changes: 4 additions & 6 deletions compiler/src/dotty/tools/dotc/config/ScalaSettings.scala
Original file line number Diff line number Diff line change
Expand Up @@ -441,12 +441,10 @@ private sealed trait YSettings:
val YlegacyLazyVals: Setting[Boolean] = BooleanSetting(ForkSetting, "Ylegacy-lazy-vals", "Use legacy (pre 3.3.0) implementation of lazy vals.")
val YcompileScala2Library: Setting[Boolean] = BooleanSetting(ForkSetting, "Ycompile-scala2-library", "Used when compiling the Scala 2 standard library.")
val YprofileEnabled: Setting[Boolean] = BooleanSetting(ForkSetting, "Yprofile-enabled", "Enable profiling.")
val YprofileDestination: Setting[String] = StringSetting(ForkSetting, "Yprofile-destination", "file", "Where to send profiling output - specify a file, default is to the console.", "")
//.withPostSetHook( _ => YprofileEnabled.value = true )
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")
//.withPostSetHook( _ => YprofileEnabled.value = true )
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 *", "_")
//.withPostSetHook( _ => YprofileEnabled.value = true )
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))
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))
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))
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))

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.")
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.")
Expand Down
15 changes: 10 additions & 5 deletions compiler/src/dotty/tools/dotc/config/Settings.scala
Original file line number Diff line number Diff line change
Expand Up @@ -73,6 +73,11 @@ object Settings:
def validateSettingString(name: String): Unit =
assert(settingCharacters.matches(name), s"Setting string $name contains invalid characters")

/** List of setting-value pairs that are required for another setting to be valid.
* For example, `s = Setting(..., depends = List(YprofileEnabled -> true))`
* means that `s` requires `YprofileEnabled` to be set to `true`.
*/
type SettingDependencies = List[(Setting[?], Any)]
WojciechMazur marked this conversation as resolved.
Show resolved Hide resolved

case class Setting[T: ClassTag] private[Settings] (
category: SettingCategory,
Expand All @@ -83,7 +88,7 @@ object Settings:
choices: Option[Seq[?]] = None,
prefix: Option[String] = None,
aliases: List[String] = Nil,
depends: List[(Setting[?], Any)] = Nil,
depends: SettingDependencies = Nil,
ignoreInvalidArgs: Boolean = false,
preferPrevious: Boolean = false,
propertyClass: Option[Class[?]] = None,
Expand Down Expand Up @@ -385,8 +390,8 @@ object Settings:
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] =
publish(Setting(category, prependName(name), descr, initialValue, aliases = aliases, preferPrevious = preferPrevious, deprecation = deprecation, ignoreInvalidArgs = ignoreInvalidArgs))

def StringSetting(category: SettingCategory, name: String, helpArg: String, descr: String, default: String, aliases: List[String] = Nil, deprecation: Option[Deprecation] = None): Setting[String] =
publish(Setting(category, prependName(name), descr, default, helpArg, aliases = aliases, deprecation = deprecation))
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] =
publish(Setting(category, prependName(name), descr, default, helpArg, aliases = aliases, deprecation = deprecation, depends = depends))

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] =
publish(Setting(category, prependName(name), descr, default, helpArg, Some(choices), aliases = aliases, legacyArgs = legacyArgs, deprecation = deprecation))
Expand All @@ -412,8 +417,8 @@ object Settings:
def PathSetting(category: SettingCategory, name: String, descr: String, default: String, aliases: List[String] = Nil, deprecation: Option[Deprecation] = None): Setting[String] =
publish(Setting(category, prependName(name), descr, default, aliases = aliases, deprecation = deprecation))

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

def PrefixSetting(category: SettingCategory, name0: String, descr: String, deprecation: Option[Deprecation] = None): Setting[List[String]] =
val name = prependName(name0)
Expand Down
1 change: 1 addition & 0 deletions compiler/src/dotty/tools/dotc/core/Contexts.scala
Original file line number Diff line number Diff line change
Expand Up @@ -769,6 +769,7 @@ object Contexts {
.updated(settingsStateLoc, settingsGroup.defaultState)
.updated(notNullInfosLoc, Nil)
.updated(compilationUnitLoc, NoCompilationUnit)
.updated(profilerLoc, Profiler.NoOp)
c._searchHistory = new SearchRoot
c._gadtState = GadtState(GadtConstraint.empty)
c
Expand Down
2 changes: 1 addition & 1 deletion compiler/src/dotty/tools/dotc/core/Phases.scala
Original file line number Diff line number Diff line change
Expand Up @@ -370,7 +370,7 @@ object Phases {
// Test that we are in a state where we need to check if the phase should be skipped for a java file,
// this prevents checking the expensive `unit.typedAsJava` unnecessarily.
val doCheckJava = skipIfJava && !isAfterLastJavaPhase
for unit <- units do
for unit <- units do ctx.profiler.onUnit(this, unit):
given unitCtx: Context = runCtx.fresh.setPhase(this.start).setCompilationUnit(unit).withRootImports
if ctx.run.enterUnit(unit) then
try
Expand Down
12 changes: 10 additions & 2 deletions compiler/src/dotty/tools/dotc/core/SymbolLoaders.scala
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ import java.nio.channels.ClosedByInterruptException
import scala.util.control.NonFatal

import dotty.tools.dotc.classpath.FileUtils.{hasTastyExtension, hasBetastyExtension}
import dotty.tools.io.{ ClassPath, ClassRepresentation, AbstractFile }
import dotty.tools.io.{ ClassPath, ClassRepresentation, AbstractFile, NoAbstractFile }
import dotty.tools.backend.jvm.DottyBackendInterface.symExtensions

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

override def complete(root: SymDenotation)(using Context): Unit = {
private inline def profileCompletion[T](root: SymDenotation)(inline body: T)(using Context): T = {
val sym = root.symbol
def associatedFile = root.symbol.associatedFile match
case file: AbstractFile => file
case _ => NoAbstractFile
ctx.profiler.onCompletion(sym, associatedFile)(body)
}

override def complete(root: SymDenotation)(using Context): Unit = profileCompletion(root) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I checked that the associatedFile callback above doesn't run when profiling is disabled ✅

But I am still not 100% convinced that is zero cost—it seems that calls to default implementations of beforeCompletion and afterCompilation will still exist after inlining? This would just be 2 method calls and a pair allocation, so maybe harmless in terms for performance?

Unfortunately, the benchmarks bot is currently down, so we can't run the benchmarks now.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The allocations have been reduced by preallocating empty (default) outputs. This should reduce any overhead when -Yprofile-trace is disabled. The 2 additional calls to before/after completion might still be present, but maybe JVM can optimize these?

Do you maybe know if the benchmarks bot is working now? We could run it now, after the rebase, to ensure the overhead is not significant when profile-tracing is disabled.

def signalError(ex: Exception): Unit = {
if (ctx.debug) ex.printStackTrace()
val msg = ex.getMessage()
Expand Down
190 changes: 190 additions & 0 deletions compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala
Original file line number Diff line number Diff line change
@@ -0,0 +1,190 @@
// Scala 2 compiler backport of https://github.com/scala/scala/pull/7364
/*
* Scala (https://www.scala-lang.org)
*
* Copyright EPFL and Lightbend, Inc.
*
* Licensed under Apache License 2.0
* (http://www.apache.org/licenses/LICENSE-2.0).
*
* See the NOTICE file distributed with this work for
* additional information regarding copyright ownership.
*/

package dotty.tools.dotc.profile

import scala.language.unsafeNulls

import java.io.Closeable
import java.lang.management.ManagementFactory
import java.nio.file.{Files, Path}
import java.util
import java.util.concurrent.TimeUnit

import scala.collection.mutable

object ChromeTrace {
Copy link
Member

@mbovel mbovel Jul 1, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I haven't read this class and FileUtils in details. Should we have a few unit tests for these, or is it not worth it?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've ported the FileUtilsTest from Scala 2 repo and added a ChromeTraceTest to check the outputs and structure of tracing files

private object EventType {
final val Start = "B"
final val Instant = "I"
final val End = "E"
final val Complete = "X"

final val Counter = "C"

final val AsyncStart = "b"
final val AsyncInstant = "n"
final val AsyncEnd = "e"
}
}

/** Allows writing a subset of captrue traces based on https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#
* 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 */
final class ChromeTrace(f: Path) extends Closeable {
import ChromeTrace.EventType
private val traceWriter = FileUtils.newAsyncBufferedWriter(f)
private val context = mutable.Stack[JsonContext](TopContext)
private val tidCache = new ThreadLocal[String]() {
override def initialValue(): String = "%05d".format(Thread.currentThread().getId())
}
objStart()
fld("traceEvents")
context.push(ValueContext)
arrStart()
traceWriter.newLine()

private val pid = ManagementFactory.getRuntimeMXBean().getName().replaceAll("@.*", "")

override def close(): Unit = {
arrEnd()
objEnd()
context.pop()
tidCache.remove()
traceWriter.close()
}

def traceDurationEvent(name: String, startNanos: Long, durationNanos: Long, tid: String = this.tid(), pidSuffix: String = ""): Unit = {
val durationMicros = nanosToMicros(durationNanos)
val startMicros = nanosToMicros(startNanos)
objStart()
str("cat", "scalac")
str("name", name)
str("ph", EventType.Complete)
str("tid", tid)
writePid(pidSuffix)
lng("ts", startMicros)
lng("dur", durationMicros)
objEnd()
traceWriter.newLine()
}

private def writePid(pidSuffix: String) = {
if (pidSuffix == "")
str("pid", pid)
else
str2("pid", pid, "-", pidSuffix)
}

def traceCounterEvent(name: String, counterName: String, count: Long, processWide: Boolean): Unit = {
objStart()
str("cat", "scalac")
str("name", name)
str("ph", EventType.Counter)
str("tid", tid())
writePid(pidSuffix = if (processWide) "" else tid())
lng("ts", microTime())
fld("args")
objStart()
lng(counterName, count)
objEnd()
objEnd()
traceWriter.newLine()
}

def traceDurationEventStart(cat: String, name: String, colour: String = "", pidSuffix: String = tid()): Unit = traceDurationEventStartEnd(EventType.Start, cat, name, colour, pidSuffix)
def traceDurationEventEnd(cat: String, name: String, colour: String = "", pidSuffix: String = tid()): Unit = traceDurationEventStartEnd(EventType.End, cat, name, colour, pidSuffix)

private def traceDurationEventStartEnd(eventType: String, cat: String, name: String, colour: String, pidSuffix: String = ""): Unit = {
objStart()
str("cat", cat)
str("name", name)
str("ph", eventType)
writePid(pidSuffix)
str("tid", tid())
lng("ts", microTime())
if (colour != "") {
str("cname", colour)
}
objEnd()
traceWriter.newLine()
}

private def tid(): String = tidCache.get()

private def nanosToMicros(t: Long): Long = TimeUnit.NANOSECONDS.toMicros(t)

private def microTime(): Long = nanosToMicros(System.nanoTime())

private sealed abstract class JsonContext
private case class ArrayContext(var first: Boolean) extends JsonContext
private case class ObjectContext(var first: Boolean) extends JsonContext
private case object ValueContext extends JsonContext
private case object TopContext extends JsonContext

private def str(name: String, value: String): Unit = {
fld(name)
traceWriter.write("\"")
traceWriter.write(value) // This assumes no escaping is needed
traceWriter.write("\"")
}
private def str2(name: String, value: String, valueContinued1: String, valueContinued2: String): Unit = {
fld(name)
traceWriter.write("\"")
traceWriter.write(value) // This assumes no escaping is needed
traceWriter.write(valueContinued1) // This assumes no escaping is needed
traceWriter.write(valueContinued2) // This assumes no escaping is needed
traceWriter.write("\"")
}
private def lng(name: String, value: Long): Unit = {
fld(name)
traceWriter.write(String.valueOf(value))
traceWriter.write("")
}
private def objStart(): Unit = {
context.top match {
case ac @ ArrayContext(first) =>
if (first) ac.first = false
else traceWriter.write(",")
case _ =>
}
context.push(ObjectContext(true))
traceWriter.write("{")
}
private def objEnd(): Unit = {
traceWriter.write("}")
context.pop()
}
private def arrStart(): Unit = {
traceWriter.write("[")
context.push(ArrayContext(true))
}
private def arrEnd(): Unit = {
traceWriter.write("]")
context.pop()
}

private def fld(name: String) = {
val topContext = context.top
topContext match {
case oc @ ObjectContext(first) =>
if (first) oc.first = false
else traceWriter.write(",")
case context =>
throw new IllegalStateException("Wrong context: " + context)
}
traceWriter.write("\"")
traceWriter.write(name)
traceWriter.write("\"")
traceWriter.write(":")
}
}
Loading
Loading