From 8c55116f673a3cccbe272de1c672229c17d0199e Mon Sep 17 00:00:00 2001 From: Wojciech Mazur Date: Thu, 7 Mar 2024 18:58:03 +0100 Subject: [PATCH] Backport -Yprofile-trace from Scala 2 Adapt PresentationCompiler to always set (by default noop) profiler --- .../tools/dotc/config/ScalaSettings.scala | 2 + .../src/dotty/tools/dotc/core/Phases.scala | 5 +- .../tools/dotc/profile/ChromeTrace.scala | 190 ++++++++++++++++ .../dotty/tools/dotc/profile/FileUtils.scala | 203 ++++++++++++++++++ .../dotty/tools/dotc/profile/Profiler.scala | 119 +++++++++- .../dotty/tools/dotc/typer/Implicits.scala | 5 +- .../src/dotty/tools/dotc/typer/Typer.scala | 21 +- .../pc/completions/CompletionProvider.scala | 6 +- 8 files changed, 531 insertions(+), 20 deletions(-) create mode 100644 compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala create mode 100644 compiler/src/dotty/tools/dotc/profile/FileUtils.scala diff --git a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala index 3dafedd8e2e0..2f14283fdf3d 100644 --- a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala +++ b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala @@ -411,6 +411,8 @@ private sealed trait YSettings: //.withPostSetHook( _ => YprofileEnabled.value = true ) val YprofileRunGcBetweenPhases: Setting[List[String]] = PhasesSetting("-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 YprofileTrace: Setting[String] = StringSetting("-Yprofile-trace", "file", "Capture trace of compilation in Chrome Trace format", "profile.trace") + //.withPostSetHook( _ => YprofileEnabled.value = true ) // Experimental language features val YnoKindPolymorphism: Setting[Boolean] = BooleanSetting("-Yno-kind-polymorphism", "Disable kind polymorphism.") diff --git a/compiler/src/dotty/tools/dotc/core/Phases.scala b/compiler/src/dotty/tools/dotc/core/Phases.scala index c704846a82da..7434d65c8b14 100644 --- a/compiler/src/dotty/tools/dotc/core/Phases.scala +++ b/compiler/src/dotty/tools/dotc/core/Phases.scala @@ -346,6 +346,7 @@ object Phases { val doSkipJava = ctx.settings.YjavaTasty.value && this <= picklerPhase && skipIfJava for unit <- units do given unitCtx: Context = runCtx.fresh.setPhase(this.start).setCompilationUnit(unit).withRootImports + ctx.profiler.beforeUnit(this, unit) if ctx.run.enterUnit(unit) then try if doSkipJava && unit.typedAsJava then @@ -355,7 +356,9 @@ object Phases { catch case ex: Throwable if !ctx.run.enrichedErrorMessage => println(ctx.run.enrichErrorMessage(s"unhandled exception while running $phaseName on $unit")) throw ex - finally ctx.run.advanceUnit() + finally + ctx.profiler.afterUnit(this, unit) + ctx.run.advanceUnit() buf += unitCtx.compilationUnit end if end for diff --git a/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala b/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala new file mode 100644 index 000000000000..956405d8a439 --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/ChromeTrace.scala @@ -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 { + 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 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 */ +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()) + + 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 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(":") + } +} \ No newline at end of file diff --git a/compiler/src/dotty/tools/dotc/profile/FileUtils.scala b/compiler/src/dotty/tools/dotc/profile/FileUtils.scala new file mode 100644 index 000000000000..97c2417d236b --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/FileUtils.scala @@ -0,0 +1,203 @@ +// 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.{BufferedWriter, IOException, OutputStreamWriter, Writer} +import java.nio.CharBuffer +import java.nio.charset.{Charset, CharsetEncoder, StandardCharsets} +import java.nio.file.{Files, OpenOption, Path} +import java.util.concurrent.LinkedBlockingQueue +import java.util.concurrent.atomic.AtomicBoolean + + +import scala.concurrent.duration.Duration +import scala.concurrent.{Await, Promise} +import scala.util.{Failure, Success} + +object FileUtils { + def newAsyncBufferedWriter(path: Path, charset: Charset = StandardCharsets.UTF_8.nn, options: Array[OpenOption] = NO_OPTIONS, threadsafe: Boolean = false): LineWriter = { + val encoder: CharsetEncoder = charset.newEncoder + val writer = new OutputStreamWriter(Files.newOutputStream(path, options: _*), encoder) + newAsyncBufferedWriter(new BufferedWriter(writer), threadsafe) + } + def newAsyncBufferedWriter(underlying: Writer, threadsafe: Boolean): LineWriter = { + val async = new AsyncBufferedWriter(underlying) + if (threadsafe) new ThreadsafeWriter(async) else async + } + private val NO_OPTIONS = new Array[OpenOption](0) + + sealed abstract class LineWriter extends Writer { + def newLine(): Unit + } + private class ThreadsafeWriter(val underlying: AsyncBufferedWriter) extends LineWriter { + lock = underlying + override def write(c: Int): Unit = + lock.synchronized (underlying.write(c)) + + override def write(cbuf: Array[Char]): Unit = + lock.synchronized (underlying.write(cbuf)) + + override def write(cbuf: Array[Char], off: Int, len: Int): Unit = + lock.synchronized (underlying.write(cbuf, off, len)) + + override def write(str: String): Unit = + lock.synchronized (underlying.write(str)) + + override def write(str: String, off: Int, len: Int): Unit = + lock.synchronized (underlying.write(str, off, len)) + + override def flush(): Unit = + lock.synchronized (underlying.flush()) + + override def close(): Unit = + lock.synchronized (underlying.close()) + + override def newLine(): Unit = + lock.synchronized (underlying.newLine()) + + } + + private object AsyncBufferedWriter { + private val Close = CharBuffer.allocate(0) + private val Flush = CharBuffer.allocate(0) + } + private class AsyncBufferedWriter(val underlying: Writer, bufferSize : Int = 4096) extends LineWriter { + private var current: CharBuffer = allocate + override def write(c: Int): Unit = super.write(c) + private def flushAsync(): Unit = { + background.ensureProcessed(current) + current = allocate + } +// allocate or reuse a CharArray which is guaranteed to have a backing array + private def allocate: CharBuffer = { + val reused = background.reuseBuffer + if (reused eq null) CharBuffer.allocate(bufferSize) + else { + //we don't care about race conditions + background.reuseBuffer = null + reused.clear() + reused + } + } + + override def write(cbuf: Array[Char], initialOffset: Int, initialLength: Int): Unit = { + var offset = initialOffset + var length = initialLength + while (length > 0) { + val capacity = current.remaining() + if (length <= capacity) { + current.put(cbuf, offset, length) + length = 0 + } else { + current.put(cbuf, offset, capacity) + flushAsync() + length -= capacity + offset += capacity + } + } + } + + override def write(s: String, initialOffset: Int, initialLength: Int): Unit = { + var offset = initialOffset + var length = initialLength + while (length > 0) { + val capacity = current.remaining() + if (length <= capacity) { + current.put(s, offset, offset + length) + length = 0 + } else { + current.put(s, offset, offset + capacity) + flushAsync() + length -= capacity + offset += capacity + } + } + } + + def newLine(): Unit = write(scala.util.Properties.lineSeparator) + + /** slightly breaks the flush contract in that the flush is not complete when the method returns */ + override def flush(): Unit = { + flushAsync() + } + + override def close(): Unit = { + background.ensureProcessed(current) + background.ensureProcessed(AsyncBufferedWriter.Close) + current = null + Await.result(background.asyncStatus.future, Duration.Inf) + underlying.close() + } + private object background extends Runnable{ + + import scala.concurrent.ExecutionContext.Implicits.global + + private val pending = new LinkedBlockingQueue[CharBuffer] + //a failure detected will case an Failure, Success indicates a close + val asyncStatus = Promise[Unit]() + private val scheduled = new AtomicBoolean + @volatile var reuseBuffer: CharBuffer = _ + + def ensureProcessed(buffer: CharBuffer): Unit = { + if (asyncStatus.isCompleted) { + asyncStatus.future.value.get match { + case Success(()) => throw new IllegalStateException("closed") + case Failure(t) => throw new IOException("async failure", t) + } + } + + //order is essential - add to the queue before the CAS + pending.add(buffer) + if (scheduled.compareAndSet(false, true)) { + global.execute(background) + } + } + + def run(): Unit = { + try { + while (!pending.isEmpty) { + val next = pending.poll() + if (next eq AsyncBufferedWriter.Flush) { + underlying.flush() + } else if (next eq AsyncBufferedWriter.Close) { + underlying.flush() + underlying.close() + asyncStatus.trySuccess(()) + } else { + val array = next.array() + next.flip() + underlying.write(array, next.arrayOffset() + next.position(), next.limit()) + reuseBuffer = next + } + } + } catch { + case t: Throwable => + asyncStatus.tryFailure(t) + throw t + } + finally scheduled.set(false) + + //we are not scheduled any more + //as a last check ensure that we didnt race with an addition to the queue + //order is essential - queue is checked before CAS + if ((!pending.isEmpty) && scheduled.compareAndSet(false, true)) { + global.execute(background) + } + } + } + } +} \ No newline at end of file diff --git a/compiler/src/dotty/tools/dotc/profile/Profiler.scala b/compiler/src/dotty/tools/dotc/profile/Profiler.scala index a13c9d41b529..a8391d34f462 100644 --- a/compiler/src/dotty/tools/dotc/profile/Profiler.scala +++ b/compiler/src/dotty/tools/dotc/profile/Profiler.scala @@ -4,6 +4,7 @@ import scala.annotation.* import scala.language.unsafeNulls import java.io.{FileWriter, PrintWriter} +import java.nio.file.Paths import java.lang.management.{ManagementFactory, GarbageCollectorMXBean, RuntimeMXBean, MemoryMXBean, ClassLoadingMXBean, CompilationMXBean} import java.util.concurrent.TimeUnit import java.util.concurrent.atomic.AtomicInteger @@ -12,6 +13,9 @@ import javax.management.{Notification, NotificationEmitter, NotificationListener import dotty.tools.dotc.core.Phases.Phase import dotty.tools.dotc.core.Contexts.* +import dotty.tools.dotc.CompilationUnit +import dotty.tools.dotc.core.Types.Type +import dotty.tools.dotc.core.Symbols.Symbol import dotty.tools.io.AbstractFile import annotation.internal.sharable @@ -25,14 +29,14 @@ object Profiler { new RealProfiler(reporter) } - private[profile] val emptySnap: ProfileSnap = ProfileSnap(0, "", 0, 0, 0, 0, 0, 0) + private[profile] val emptySnap: ProfileSnap = ProfileSnap(0, "", 0, 0, 0, 0, 0, 0, 0, 0) } case class GcEventData(pool:String, reportTimeNs: Long, gcStartMillis:Long, gcEndMillis:Long, name:String, action:String, cause:String, threads:Long) case class ProfileSnap(threadId: Long, threadName: String, snapTimeNanos : Long, idleTimeNanos:Long, cpuTimeNanos: Long, userTimeNanos: Long, - allocatedBytes:Long, heapBytes:Long) { + allocatedBytes:Long, heapBytes:Long,totalClassesLoaded: Long, totalJITCompilationTime: Long) { def updateHeap(heapBytes:Long): ProfileSnap = copy(heapBytes = heapBytes) } @@ -73,6 +77,18 @@ sealed trait Profiler { def beforePhase(phase: Phase): ProfileSnap def afterPhase(phase: Phase, profileBefore: ProfileSnap): Unit + + def beforeUnit(phase: Phase, unit: CompilationUnit): Unit = () + def afterUnit(phase: Phase, unit: CompilationUnit): Unit = () + + def beforeTypedImplDef(sym: Symbol): Unit = () + def afterTypedImplDef(sym: Symbol): Unit = () + + def beforeImplicitSearch(pt: Type): Unit = () + def afterImplicitSearch(pt: Type): Unit = () + + def beforeCompletion(root: Symbol, associatedFile: AbstractFile): Unit = () + def afterCompletion(root: Symbol, associatedFile: AbstractFile): Unit = () } private [profile] object NoOpProfiler extends Profiler { @@ -104,6 +120,28 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) private val mainThread = Thread.currentThread() + enum Category: + def name: String = this.toString().toLowerCase() + case Run, Phase, File, TypeCheck, Implicit, Macro, Completion + given Conversion[Category, String] = _.name + + + private [profile] val chromeTrace = + if ctx.settings.YprofileTrace.isDefault + then null + else + // Scala 2 combined traces from different runs by storing them in buffer + // It would lead to high memory usage when profiling larger codebases + // Instead create file with suffix for subsequent runs + val filename = ctx.settings.YprofileTrace.value + val suffix = if(id > 1) s".$id" else "" + ChromeTrace(Paths.get(s"$filename$suffix")) + private var nextAfterUnitSnap:Long = System.nanoTime() + + if chromeTrace != null + then chromeTrace.traceDurationEventStart(Category.Run, "scalac-" + id) + + @nowarn("cat=deprecation") private[profile] def snapThread(idleTimeNanos: Long): ProfileSnap = { import RealProfiler.* @@ -117,7 +155,10 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) cpuTimeNanos = threadMx.getCurrentThreadCpuTime, userTimeNanos = threadMx.getCurrentThreadUserTime, allocatedBytes = threadMx.getThreadAllocatedBytes(Thread.currentThread().getId), - heapBytes = readHeapUsage() + heapBytes = readHeapUsage(), + totalClassesLoaded = classLoaderMx.getTotalLoadedClassCount, + totalJITCompilationTime = compileMx.getTotalCompilationTime + ) } private def readHeapUsage() = RealProfiler.memoryMx.getHeapMemoryUsage.getUsed @@ -142,6 +183,10 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) case gc => } reporter.close(this) + if chromeTrace != null then + chromeTrace.traceDurationEventEnd(Category.Run, "scalac-" + id) + chromeTrace.close() + } @@ -164,7 +209,7 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) val startTime = info.get("startTime").asInstanceOf[jLong].longValue() val endTime = info.get("endTime").asInstanceOf[jLong].longValue() val threads = info.get("GcThreadCount").asInstanceOf[jInt].longValue() - reporter.reportGc(GcEventData("", reportNs, startTime, endTime, name, action, cause, threads)) + reporter.reportGc(this, GcEventData("", reportNs, startTime, endTime, name, action, cause, threads)) } } @@ -181,11 +226,17 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) } else initialSnap + if chromeTrace != null + then chromeTrace.traceDurationEventEnd(Category.Phase, phase.phaseName) + reporter.reportForeground(this, ProfileRange(snapBefore, finalSnap, phase, "", 0, Thread.currentThread)) } override def beforePhase(phase: Phase): ProfileSnap = { assert(mainThread eq Thread.currentThread()) + if chromeTrace != null + then chromeTrace.traceDurationEventStart(Category.Phase, phase.phaseName) + if (ctx.settings.YprofileRunGcBetweenPhases.value.contains(phase.toString)) doGC if (ctx.settings.YprofileExternalTool.value.contains(phase.toString)) { @@ -194,8 +245,49 @@ private [profile] class RealProfiler(reporter : ProfileReporter)(using Context) } snapThread(0) } -} + override def beforeUnit(phase: Phase, unit: CompilationUnit): Unit = { + assert(mainThread eq Thread.currentThread()) + if (chromeTrace != null) chromeTrace.traceDurationEventStart(Category.File, unit.source.name) + } + + override def afterUnit(phase: Phase, unit: CompilationUnit): Unit = { + assert(mainThread eq Thread.currentThread()) + if (chromeTrace != null) { + val now = System.nanoTime() + chromeTrace.traceDurationEventEnd(Category.File, unit.source.name) + if (now > nextAfterUnitSnap) { + val initialSnap = snapThread(0) + chromeTrace.nn.traceCounterEvent("allocBytes", "allocBytes", initialSnap.allocatedBytes, processWide = false) + chromeTrace.nn.traceCounterEvent("heapBytes", "heapBytes", initialSnap.heapBytes, processWide = true) + chromeTrace.nn.traceCounterEvent("classesLoaded", "classesLoaded", initialSnap.totalClassesLoaded, processWide = true) + chromeTrace.nn.traceCounterEvent("jitCompilationTime", "jitCompilationTime", initialSnap.totalJITCompilationTime, processWide = true) + chromeTrace.nn.traceCounterEvent("userTime", "userTime", initialSnap.userTimeNanos, processWide = false) + chromeTrace.nn.traceCounterEvent("cpuTime", "cpuTime", initialSnap.cpuTimeNanos, processWide = false) + chromeTrace.nn.traceCounterEvent("idleTime", "idleTime", initialSnap.idleTimeNanos, processWide = false) + nextAfterUnitSnap = System.nanoTime() + 10 * 1000 * 1000 + } + } + } + + override def beforeTypedImplDef(sym: Symbol): Unit = + if chromeTrace != null + then chromeTrace.traceDurationEventStart(Category.TypeCheck, sym.fullName.toString) + + override def afterTypedImplDef(sym: Symbol): Unit = + if chromeTrace != null + then chromeTrace.traceDurationEventEnd(Category.TypeCheck, sym.fullName.toString) + + override def beforeImplicitSearch(pt: Type): Unit = + if chromeTrace != null + then chromeTrace.traceDurationEventStart(Category.Implicit, "?[" + pt.typeSymbol.fullName + "]", colour = "yellow") + + + override def afterImplicitSearch(pt: Type): Unit = + if chromeTrace != null + then chromeTrace.traceDurationEventEnd(Category.Implicit, "?[" + pt.typeSymbol.fullName + "]", colour = "yellow") + +} case class EventType(name: String) object EventType { @@ -211,7 +303,7 @@ sealed trait ProfileReporter { def reportBackground(profiler: RealProfiler, threadRange: ProfileRange): Unit def reportForeground(profiler: RealProfiler, threadRange: ProfileRange): Unit - def reportGc(data: GcEventData): Unit + def reportGc(profiler: RealProfiler, data: GcEventData): Unit def header(profiler: RealProfiler) :Unit def close(profiler: RealProfiler) :Unit @@ -234,8 +326,13 @@ object ConsoleProfileReporter extends ProfileReporter { override def header(profiler: RealProfiler): Unit = println(s"Profiler start (${profiler.id}) ${profiler.outDir}") - override def reportGc(data: GcEventData): Unit = + override def reportGc(profiler: RealProfiler, data: GcEventData): Unit = println(s"Profiler GC reported ${data.gcEndMillis - data.gcStartMillis}ms") + if(profiler.chromeTrace != null){ + val duration = TimeUnit.MILLISECONDS.toNanos(data.gcEndMillis - data.gcStartMillis + 1) + val start = data.reportTimeNs - duration + profiler.chromeTrace.traceDurationEvent(data.name, start, duration, EventType.GC.name) + } } class StreamProfileReporter(out:PrintWriter) extends ProfileReporter { @@ -253,15 +350,17 @@ class StreamProfileReporter(out:PrintWriter) extends ProfileReporter { private def reportCommon(tpe:EventType, profiler: RealProfiler, threadRange: ProfileRange): Unit = out.println(s"$tpe,${threadRange.start.snapTimeNanos},${threadRange.end.snapTimeNanos},${profiler.id},${threadRange.phase.id},${threadRange.phase.phaseName.replace(',', ' ')},${threadRange.purpose},${threadRange.taskCount},${threadRange.thread.getId},${threadRange.thread.getName},${threadRange.runNs},${threadRange.idleNs},${threadRange.cpuNs},${threadRange.userNs},${threadRange.allocatedBytes},${threadRange.end.heapBytes} ") - override def reportGc(data: GcEventData): Unit = { + override def reportGc(profiler: RealProfiler, data: GcEventData): Unit = { val duration = TimeUnit.MILLISECONDS.toNanos(data.gcEndMillis - data.gcStartMillis + 1) val start = data.reportTimeNs - duration out.println(s"${EventType.GC},$start,${data.reportTimeNs},${data.gcStartMillis}, ${data.gcEndMillis},${data.name},${data.action},${data.cause},${data.threads}") + if profiler.chromeTrace != null + then profiler.chromeTrace.traceDurationEvent(data.name, start, duration, EventType.GC.name) } override def close(profiler: RealProfiler): Unit = { - out.flush - out.close + out.flush() + out.close() } } diff --git a/compiler/src/dotty/tools/dotc/typer/Implicits.scala b/compiler/src/dotty/tools/dotc/typer/Implicits.scala index 0a26ea697a6a..a99b9cbdf1c1 100644 --- a/compiler/src/dotty/tools/dotc/typer/Implicits.scala +++ b/compiler/src/dotty/tools/dotc/typer/Implicits.scala @@ -1068,7 +1068,8 @@ trait Implicits: * @param span The position where errors should be reported. */ def inferImplicit(pt: Type, argument: Tree, span: Span)(using Context): SearchResult = - trace(s"search implicit ${pt.show}, arg = ${argument.show}: ${argument.tpe.show}", implicits, show = true) { + ctx.profiler.beforeImplicitSearch(pt) + try trace(s"search implicit ${pt.show}, arg = ${argument.show}: ${argument.tpe.show}", implicits, show = true) { record("inferImplicit") assert(ctx.phase.allowsImplicitSearch, if (argument.isEmpty) i"missing implicit parameter of type $pt after typer at phase ${ctx.phase.phaseName}" @@ -1130,7 +1131,7 @@ trait Implicits: } // If we are at the outermost implicit search then emit the implicit dictionary, if any. ctx.searchHistory.emitDictionary(span, result) - } + } finally ctx.profiler.afterImplicitSearch(pt) /** Try to typecheck an implicit reference */ def typedImplicit(cand: Candidate, pt: Type, argument: Tree, span: Span)(using Context): SearchResult = trace(i"typed implicit ${cand.ref}, pt = $pt, implicitsEnabled == ${ctx.mode is ImplicitsEnabled}", implicits, show = true) { diff --git a/compiler/src/dotty/tools/dotc/typer/Typer.scala b/compiler/src/dotty/tools/dotc/typer/Typer.scala index 47bd25e5d45e..ad93557a5a31 100644 --- a/compiler/src/dotty/tools/dotc/typer/Typer.scala +++ b/compiler/src/dotty/tools/dotc/typer/Typer.scala @@ -2538,7 +2538,9 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer if filters == List(MessageFilter.None) then sup.markUsed() ctx.run.nn.suppressions.addSuppression(sup) - def typedValDef(vdef: untpd.ValDef, sym: Symbol)(using Context): Tree = { + def typedValDef(vdef: untpd.ValDef, sym: Symbol)(using Context): Tree = + ctx.profiler.beforeTypedImplDef(sym) + try { val ValDef(name, tpt, _) = vdef checkNonRootName(vdef.name, vdef.nameSpan) completeAnnotations(vdef, sym) @@ -2552,9 +2554,11 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer val vdef1 = assignType(cpy.ValDef(vdef)(name, tpt1, rhs1), sym) postProcessInfo(vdef1, sym) vdef1.setDefTree - } + } finally ctx.profiler.afterTypedImplDef(sym) - def typedDefDef(ddef: untpd.DefDef, sym: Symbol)(using Context): Tree = { + def typedDefDef(ddef: untpd.DefDef, sym: Symbol)(using Context): Tree = + ctx.profiler.beforeTypedImplDef(sym) + try { def canBeInvalidated(sym: Symbol): Boolean = sym.is(Synthetic) && (desugar.isRetractableCaseClassMethodName(sym.name) || @@ -2663,7 +2667,7 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer postProcessInfo(ddef2, sym) ddef2.setDefTree //todo: make sure dependent method types do not depend on implicits or by-name params - } + } finally ctx.profiler.afterTypedImplDef(sym) /** (1) Check that the signature of the class member does not return a repeated parameter type * (2) If info is an erased class, set erased flag of member @@ -2676,6 +2680,8 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer sym.setFlag(Erased) def typedTypeDef(tdef: untpd.TypeDef, sym: Symbol)(using Context): Tree = { + ctx.profiler.beforeTypedImplDef(sym) + try { val TypeDef(name, rhs) = tdef completeAnnotations(tdef, sym) val rhs1 = tdef.rhs match @@ -2686,9 +2692,12 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer checkFullyAppliedType(rhs1) if sym.isOpaqueAlias then checkNoContextFunctionType(rhs1) assignType(cpy.TypeDef(tdef)(name, rhs1), sym) + } finally ctx.profiler.beforeTypedImplDef(sym) } - def typedClassDef(cdef: untpd.TypeDef, cls: ClassSymbol)(using Context): Tree = { + def typedClassDef(cdef: untpd.TypeDef, cls: ClassSymbol)(using Context): Tree = + ctx.profiler.beforeTypedImplDef(cls) + try { if (!cls.info.isInstanceOf[ClassInfo]) return EmptyTree.assertingErrorsReported val TypeDef(name, impl @ Template(constr, _, self, _)) = cdef: @unchecked @@ -2840,7 +2849,7 @@ class Typer(@constructorOnly nestingLevel: Int = 0) extends Namer cdef1 } - } + } finally ctx.profiler.afterTypedImplDef(cls) // todo later: check that // 1. If class is non-abstract, it is instantiatable: diff --git a/presentation-compiler/src/main/dotty/tools/pc/completions/CompletionProvider.scala b/presentation-compiler/src/main/dotty/tools/pc/completions/CompletionProvider.scala index a583e31a9e0c..48ad72902972 100644 --- a/presentation-compiler/src/main/dotty/tools/pc/completions/CompletionProvider.scala +++ b/presentation-compiler/src/main/dotty/tools/pc/completions/CompletionProvider.scala @@ -18,6 +18,7 @@ import dotty.tools.dotc.core.StdNames import dotty.tools.dotc.interactive.Interactive import dotty.tools.dotc.interactive.InteractiveDriver import dotty.tools.dotc.util.SourceFile +import dotty.tools.dotc.profile.Profiler import dotty.tools.pc.AutoImports.AutoImportEdits import dotty.tools.pc.AutoImports.AutoImportsGenerator import dotty.tools.pc.printer.ShortenedTypePrinter @@ -54,7 +55,10 @@ class CompletionProvider( val (items, isIncomplete) = driver.compilationUnits.get(uri) match case Some(unit) => - val newctx = ctx.fresh.setCompilationUnit(unit).withPhase(Phases.typerPhase(using ctx)) + val newctx = ctx.fresh + .setCompilationUnit(unit) + .setProfiler(Profiler()(using ctx)) + .withPhase(Phases.typerPhase(using ctx)) val tpdPath = Interactive.pathTo(newctx.compilationUnit.tpdTree, pos.span)(using newctx) val adjustedPath = Interactive.resolveTypedOrUntypedPath(tpdPath, pos)(using newctx)