From c01603552ba022580cc5a2ba00c9d7e4bd6c19f5 Mon Sep 17 00:00:00 2001 From: Wojciech Mazur Date: Fri, 13 Sep 2024 12:29:55 +0200 Subject: [PATCH] Reduce ammount of allocations, increase ammontof counters tracing and other cleanups --- .../tools/dotc/config/ScalaSettings.scala | 2 +- .../tools/dotc/profile/ChromeTrace.scala | 14 ++-- .../dotty/tools/dotc/profile/Profiler.scala | 71 ++++++++++--------- 3 files changed, 44 insertions(+), 43 deletions(-) diff --git a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala index 4ea7d45bae45..6b38e45e27c7 100644 --- a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala +++ b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala @@ -410,7 +410,7 @@ private sealed trait YSettings: 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 Chrome Trace format, requires ${YprofileEnabled.name}", "", 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)) // Experimental language features val YnoKindPolymorphism: Setting[Boolean] = BooleanSetting(ForkSetting, "Yno-kind-polymorphism", "Disable kind polymorphism.") diff --git a/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala b/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala index 956405d8a439..c33039f46398 100644 --- a/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala +++ b/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala @@ -38,8 +38,8 @@ object ChromeTrace { } } -/** Allows writing a subset of https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview# - * for use in Chrome's about://tracing 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 */ +/** 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) @@ -125,11 +125,11 @@ final class ChromeTrace(f: Path) extends Closeable { private def microTime(): Long = nanosToMicros(System.nanoTime()) - sealed abstract class JsonContext - case class ArrayContext(var first: Boolean) extends JsonContext - case class ObjectContext(var first: Boolean) extends JsonContext - case object ValueContext extends JsonContext - case object TopContext extends JsonContext + 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) diff --git a/compiler/src/dotty/tools/dotc/profile/Profiler.scala b/compiler/src/dotty/tools/dotc/profile/Profiler.scala index 77fec6757ac8..69a806215ddd 100644 --- a/compiler/src/dotty/tools/dotc/profile/Profiler.scala +++ b/compiler/src/dotty/tools/dotc/profile/Profiler.scala @@ -92,7 +92,8 @@ sealed trait Profiler { val (event, snapshot) = beforePhase(phase) try body finally afterPhase(event, phase, snapshot) - protected def beforePhase(phase: Phase): (TracedEventId, ProfileSnap) = (TracedEventId.Empty, Profiler.emptySnap) + protected final val EmptyPhaseEvent = (TracedEventId.Empty, Profiler.emptySnap) + protected def beforePhase(phase: Phase): (TracedEventId, ProfileSnap) = EmptyPhaseEvent protected def afterPhase(event: TracedEventId, phase: Phase, profileBefore: ProfileSnap): Unit = () inline def onUnit[T](phase: Phase, unit: CompilationUnit)(inline body: T): T = @@ -127,13 +128,14 @@ sealed trait Profiler { val (event, completionName) = beforeCompletion(root, associatedFile) try body finally afterCompletion(event, completionName) - protected def beforeCompletion(root: Symbol, associatedFile: => AbstractFile): (TracedEventId, String) = (TracedEventId.Empty, "") + protected final val EmptyCompletionEvent = (TracedEventId.Empty, "") + protected def beforeCompletion(root: Symbol, associatedFile: => AbstractFile): (TracedEventId, String) = EmptyCompletionEvent protected def afterCompletion(event: TracedEventId, completionName: String): Unit = () } private [profile] object NoOpProfiler extends Profiler { - override def finished(): Unit = () } + private [profile] object RealProfiler { import scala.jdk.CollectionConverters.* val runtimeMx: RuntimeMXBean = ManagementFactory.getRuntimeMXBean @@ -234,10 +236,7 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) import java.lang.{Integer => jInt} val reportNs = System.nanoTime() val data = notification.getUserData - // val seq = notification.getSequenceNumber - // val message = notification.getMessage val tpe = notification.getType - // val time= notification.getTimeStamp data match { case cd: CompositeData if tpe == "com.sun.management.gc.notification" => val name = cd.get("gcName").toString @@ -267,12 +266,13 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) } else initialSnap traceDurationEnd(Category.Phase, event) - + traceThreadSnapshotCounters() reporter.reportForeground(this, ProfileRange(snapBefore, finalSnap, phase, "", 0, Thread.currentThread)) } override def beforePhase(phase: Phase): (TracedEventId, ProfileSnap) = { assert(mainThread eq Thread.currentThread()) + traceThreadSnapshotCounters() val eventId = traceDurationStart(Category.Phase, phase.phaseName) if (ctx.settings.YprofileRunGcBetweenPhases.value.contains(phase.toString)) doGC() @@ -285,26 +285,32 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) override def beforeUnit(phase: Phase, unit: CompilationUnit): TracedEventId = { assert(mainThread eq Thread.currentThread()) - traceDurationStart(Category.File, unit.source.name) + if chromeTrace != null then + traceThreadSnapshotCounters() + traceDurationStart(Category.File, unit.source.name) + else TracedEventId.Empty } override def afterUnit(event: TracedEventId): Unit = { assert(mainThread eq Thread.currentThread()) if chromeTrace != null then - val now = System.nanoTime() traceDurationEnd(Category.File, event) - if now > nextAfterUnitSnap then - val initialSnap = RealProfiler.snapThread(0) - chromeTrace.traceCounterEvent("allocBytes", "allocBytes", initialSnap.allocatedBytes, processWide = false) - chromeTrace.traceCounterEvent("heapBytes", "heapBytes", initialSnap.heapBytes, processWide = true) - chromeTrace.traceCounterEvent("classesLoaded", "classesLoaded", initialSnap.totalClassesLoaded, processWide = true) - chromeTrace.traceCounterEvent("jitCompilationTime", "jitCompilationTime", initialSnap.totalJITCompilationTime, processWide = true) - chromeTrace.traceCounterEvent("userTime", "userTime", initialSnap.userTimeNanos, processWide = false) - chromeTrace.traceCounterEvent("cpuTime", "cpuTime", initialSnap.cpuTimeNanos, processWide = false) - chromeTrace.traceCounterEvent("idleTime", "idleTime", initialSnap.idleTimeNanos, processWide = false) - nextAfterUnitSnap = System.nanoTime() + 10 * 1000 * 1000 + traceThreadSnapshotCounters() } + private def traceThreadSnapshotCounters(initialSnap: => ProfileSnap = RealProfiler.snapThread(0)) = + if chromeTrace != null && System.nanoTime() > nextAfterUnitSnap then { + val snap = initialSnap + chromeTrace.traceCounterEvent("allocBytes", "allocBytes", snap.allocatedBytes, processWide = false) + chromeTrace.traceCounterEvent("heapBytes", "heapBytes", snap.heapBytes, processWide = true) + chromeTrace.traceCounterEvent("classesLoaded", "classesLoaded", snap.totalClassesLoaded, processWide = true) + chromeTrace.traceCounterEvent("jitCompilationTime", "jitCompilationTime", snap.totalJITCompilationTime, processWide = true) + chromeTrace.traceCounterEvent("userTime", "userTime", snap.userTimeNanos, processWide = false) + chromeTrace.traceCounterEvent("cpuTime", "cpuTime", snap.cpuTimeNanos, processWide = false) + chromeTrace.traceCounterEvent("idleTime", "idleTime", snap.idleTimeNanos, processWide = false) + nextAfterUnitSnap = System.nanoTime() + 10 * 1000 * 1000 + } + override def beforeTypedDef(sym: Symbol): TracedEventId = traceDurationStart(Category.TypeCheck, symbolName(sym)) override def afterTypedDef(event: TracedEventId): Unit = traceDurationEnd(Category.TypeCheck, event) @@ -316,9 +322,9 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) override def beforeCompletion(root: Symbol, associatedFile: => AbstractFile): (TracedEventId, String) = if chromeTrace == null - then (TracedEventId.Empty, "") + then EmptyCompletionEvent else - val completionName= this.completionName(root, associatedFile) + val completionName = this.completionName(root, associatedFile) val event = TracedEventId(associatedFile.name) chromeTrace.traceDurationEventStart(Category.Completion.name, "↯", colour = "thread_state_sleeping") chromeTrace.traceDurationEventStart(Category.File.name, event) @@ -332,7 +338,6 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) chromeTrace.traceDurationEventEnd(Category.File.name, event) chromeTrace.traceDurationEventEnd(Category.Completion.name, "↯", colour = "thread_state_sleeping") - private inline def traceDurationStart(category: Category, inline eventName: String, colour: String = ""): TracedEventId = if chromeTrace == null then TracedEventId.Empty @@ -342,9 +347,8 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) event private inline def traceDurationEnd(category: Category, event: TracedEventId, colour: String = ""): Unit = - if chromeTrace != null - then chromeTrace.traceDurationEventEnd(category.name, event, colour) - + if chromeTrace != null then + chromeTrace.traceDurationEventEnd(category.name, event, colour) private def symbolName(sym: Symbol): String = s"${sym.showKind} ${sym.showName}" private def completionName(root: Symbol, associatedFile: AbstractFile): String = @@ -356,15 +360,13 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) s"${enclosing.javaBinaryName}::${root.name}" } -case class EventType(name: String) -object EventType { - //main thread with other tasks - val MAIN: EventType = EventType("main") - //other task ( background thread) - val BACKGROUND: EventType = EventType("background") - //total for compile - val GC: EventType = EventType("GC") -} +enum EventType(name: String): + // main thread with other tasks + case MAIN extends EventType("main") + // other task ( background thread) + case BACKGROUND extends EventType("background") + // total for compile + case GC extends EventType("GC") sealed trait ProfileReporter { def reportBackground(profiler: RealProfiler, threadRange: ProfileRange): Unit @@ -418,7 +420,6 @@ class StreamProfileReporter(out:PrintWriter) extends ProfileReporter { out.println(s"${EventType.GC},$start,${data.reportTimeNs},${data.gcStartMillis}, ${data.gcEndMillis},${data.name},${data.action},${data.cause},${data.threads}") } - override def close(profiler: RealProfiler): Unit = { out.flush() out.close()