diff --git a/AUTHORS.md b/AUTHORS.md index e197a6c5c71e..76a1d8e89acb 100644 --- a/AUTHORS.md +++ b/AUTHORS.md @@ -34,6 +34,11 @@ The majority of the dotty codebase is new code, with the exception of the compon > The lexical and syntactic analysis components were adapted from the current Scala compiler. They were originally authored by Martin Odersky, > Burak Emir, Paul Phillips, Lex Spoon, Sean McDirmid and others. +`dotty.tools.dotc.profile` + +> The per-phase profiling support is taken mostly as is from [scala/scala](https://github.com/scala/scala). +> The original author was Mike Skells. + `dotty.tools.dotc.reporting` > Adapted from [scala/scala](https://github.com/scala/scala) with some heavy modifications. They were originally authored by Matthias Zenger, Martin Odersky, and others. diff --git a/compiler/src/dotty/tools/dotc/Run.scala b/compiler/src/dotty/tools/dotc/Run.scala index 282975f86a0f..63a4a4992155 100644 --- a/compiler/src/dotty/tools/dotc/Run.scala +++ b/compiler/src/dotty/tools/dotc/Run.scala @@ -8,15 +8,18 @@ import Symbols._ import Phases._ import Types._ import Scopes._ -import typer.{FrontEnd, Typer, ImportInfo, RefChecks} +import typer.{FrontEnd, ImportInfo, RefChecks, Typer} import Decorators._ import io.{AbstractFile, PlainFile} + import scala.io.Codec import util.{Set => _, _} import reporting.Reporter import transform.TreeChecker import rewrite.Rewrites import java.io.{BufferedWriter, OutputStreamWriter} + +import dotty.tools.dotc.profile.Profiler import printing.XprintMode import parsing.Parsers.Parser import typer.ImplicitRunInfo @@ -24,6 +27,7 @@ import collection.mutable import scala.annotation.tailrec import dotty.tools.io.VirtualFile + import scala.util.control.NonFatal /** A compiler run. Exports various methods to compile source files */ @@ -156,11 +160,15 @@ class Run(comp: Compiler, ictx: Context) extends ImplicitRunInfo with Constraint def runPhases(implicit ctx: Context) = { var lastPrintedTree: PrintedTree = NoPrintedTree + val profiler = ctx.profiler + for (phase <- ctx.allPhases) if (phase.isRunnable) Stats.trackTime(s"$phase ms ") { val start = System.currentTimeMillis + val profileBefore = profiler.beforePhase(phase) units = phase.runOn(units) + profiler.afterPhase(phase, profileBefore) if (ctx.settings.Xprint.value.containsPhase(phase)) { for (unit <- units) { lastPrintedTree = @@ -172,9 +180,12 @@ class Run(comp: Compiler, ictx: Context) extends ImplicitRunInfo with Constraint for (unit <- units) Stats.record(s"retained typed trees at end of $phase", unit.tpdTree.treeSize) } + + profiler.finished() } val runCtx = ctx.fresh + runCtx.setProfiler(Profiler()) ctx.phases.foreach(_.initContext(runCtx)) runPhases(runCtx) if (!ctx.reporter.hasErrors) Rewrites.writeBack() diff --git a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala index a9ed9642b7b8..9d8471bc178d 100644 --- a/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala +++ b/compiler/src/dotty/tools/dotc/config/ScalaSettings.scala @@ -113,6 +113,14 @@ class ScalaSettings extends Settings.SettingGroup { val YretainTrees = BooleanSetting("-Yretain-trees", "Retain trees for top-level classes, accessible from ClassSymbol#tree") val YshowTreeIds = BooleanSetting("-Yshow-tree-ids", "Uniquely tag all tree nodes in debugging output.") + val YprofileEnabled = BooleanSetting("-Yprofile-enabled", "Enable profiling.") + val YprofileDestination = StringSetting("-Yprofile-destination", "file", "where to send profiling output - specify a file, default is to the console.", "") + //.withPostSetHook( _ => YprofileEnabled.value = true ) + val YprofileExternalTool = PhasesSetting("-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 = 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 ) + /** Area-specific debug output */ val YexplainLowlevel = BooleanSetting("-Yexplain-lowlevel", "When explaining type errors, show types at a lower level.") val YnoDoubleBindings = BooleanSetting("-Yno-double-bindings", "Assert no namedtype is bound twice (should be enabled only if program is error-free).") diff --git a/compiler/src/dotty/tools/dotc/core/Contexts.scala b/compiler/src/dotty/tools/dotc/core/Contexts.scala index 1a7b0e971a72..dc407692f71f 100644 --- a/compiler/src/dotty/tools/dotc/core/Contexts.scala +++ b/compiler/src/dotty/tools/dotc/core/Contexts.scala @@ -17,7 +17,7 @@ import Comments._ import util.Positions._ import ast.Trees._ import ast.untpd -import util.{FreshNameCreator, SimpleIdentityMap, SourceFile, NoSource} +import util.{FreshNameCreator, NoSource, SimpleIdentityMap, SourceFile} import typer.{Implicits, ImportInfo, Inliner, NamerContextOps, SearchHistory, TypeAssigner, Typer} import Implicits.ContextualImplicits import config.Settings._ @@ -27,9 +27,11 @@ import reporting.diagnostic.Message import collection.mutable import collection.immutable.BitSet import printing._ -import config.{Settings, ScalaSettings, Platform, JavaPlatform} +import config.{JavaPlatform, Platform, ScalaSettings, Settings} + import language.implicitConversions import DenotTransformers.DenotTransformer +import dotty.tools.dotc.profile.Profiler import util.Property.Key import util.Store import xsbti.AnalysisCallback @@ -43,7 +45,8 @@ object Contexts { private val (freshNamesLoc, store5) = store4.newLocation[FreshNameCreator](new FreshNameCreator.Default) private val (compilationUnitLoc, store6) = store5.newLocation[CompilationUnit]() private val (runLoc, store7) = store6.newLocation[Run]() - private val initialStore = store7 + private val (profilerLoc, store8) = store7.newLocation[Profiler]() + private val initialStore = store8 /** A context is passed basically everywhere in dotc. * This is convenient but carries the risk of captured contexts in @@ -196,6 +199,9 @@ object Contexts { /** The current compiler-run */ def run: Run = store(runLoc) + /** The current compiler-run profiler */ + def profiler: Profiler = store(profilerLoc) + /** The new implicit references that are introduced by this scope */ protected var implicitsCache: ContextualImplicits = null def implicits: ContextualImplicits = { @@ -460,6 +466,7 @@ object Contexts { def setSettings(settingsState: SettingsState): this.type = updateStore(settingsStateLoc, settingsState) def setCompilationUnit(compilationUnit: CompilationUnit): this.type = updateStore(compilationUnitLoc, compilationUnit) def setRun(run: Run): this.type = updateStore(runLoc, run) + def setProfiler(profiler: Profiler): this.type = updateStore(profilerLoc, profiler) def setFreshNames(freshNames: FreshNameCreator): this.type = updateStore(freshNamesLoc, freshNames) def setProperty[T](key: Key[T], value: T): this.type = diff --git a/compiler/src/dotty/tools/dotc/profile/AsyncHelper.scala b/compiler/src/dotty/tools/dotc/profile/AsyncHelper.scala new file mode 100644 index 000000000000..f0f5bbc84441 --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/AsyncHelper.scala @@ -0,0 +1,139 @@ +package dotty.tools.dotc.profile + +import java.util.concurrent.ThreadPoolExecutor.AbortPolicy +import java.util.concurrent._ +import java.util.concurrent.atomic.AtomicInteger + +import dotty.tools.dotc.core.Phases.Phase +import dotty.tools.dotc.core.Contexts.Context + +sealed trait AsyncHelper { + + def newUnboundedQueueFixedThreadPool + (nThreads: Int, + shortId: String, priority : Int = Thread.NORM_PRIORITY) : ThreadPoolExecutor + def newBoundedQueueFixedThreadPool + (nThreads: Int, maxQueueSize: Int, rejectHandler: RejectedExecutionHandler, + shortId: String, priority : Int = Thread.NORM_PRIORITY) : ThreadPoolExecutor + +} + +object AsyncHelper { + def apply(phase: Phase)(implicit ctx: Context): AsyncHelper = ctx.profiler match { + case NoOpProfiler => new BasicAsyncHelper(phase) + case r: RealProfiler => new ProfilingAsyncHelper(phase, r) + } + + private abstract class BaseAsyncHelper(phase: Phase)(implicit ctx: Context) extends AsyncHelper { + val baseGroup = new ThreadGroup(s"dotc-${phase.phaseName}") + private def childGroup(name: String) = new ThreadGroup(baseGroup, name) + + protected def wrapRunnable(r: Runnable, shortId:String): Runnable + + protected class CommonThreadFactory(shortId: String, + daemon: Boolean = true, + priority: Int) extends ThreadFactory { + private val group: ThreadGroup = childGroup(shortId) + private val threadNumber: AtomicInteger = new AtomicInteger(1) + private val namePrefix = s"${baseGroup.getName}-$shortId-" + + override def newThread(r: Runnable): Thread = { + val wrapped = wrapRunnable(r, shortId) + val t: Thread = new Thread(group, wrapped, namePrefix + threadNumber.getAndIncrement, 0) + if (t.isDaemon != daemon) t.setDaemon(daemon) + if (t.getPriority != priority) t.setPriority(priority) + t + } + } + } + + private final class BasicAsyncHelper(phase: Phase)(implicit ctx: Context) extends BaseAsyncHelper(phase) { + + override def newUnboundedQueueFixedThreadPool(nThreads: Int, shortId: String, priority: Int): ThreadPoolExecutor = { + val threadFactory = new CommonThreadFactory(shortId, priority = priority) + //like Executors.newFixedThreadPool + new ThreadPoolExecutor(nThreads, nThreads, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue[Runnable], threadFactory) + } + + override def newBoundedQueueFixedThreadPool(nThreads: Int, maxQueueSize: Int, rejectHandler: RejectedExecutionHandler, shortId: String, priority: Int): ThreadPoolExecutor = { + val threadFactory = new CommonThreadFactory(shortId, priority = priority) + //like Executors.newFixedThreadPool + new ThreadPoolExecutor(nThreads, nThreads, 0L, TimeUnit.MILLISECONDS, new ArrayBlockingQueue[Runnable](maxQueueSize), threadFactory, rejectHandler) + } + + override protected def wrapRunnable(r: Runnable, shortId:String): Runnable = r + } + + private class ProfilingAsyncHelper(phase: Phase, private val profiler: RealProfiler)(implicit ctx: Context) extends BaseAsyncHelper(phase) { + + override def newUnboundedQueueFixedThreadPool(nThreads: Int, shortId: String, priority: Int): ThreadPoolExecutor = { + val threadFactory = new CommonThreadFactory(shortId, priority = priority) + //like Executors.newFixedThreadPool + new SinglePhaseInstrumentedThreadPoolExecutor(nThreads, nThreads, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue[Runnable], threadFactory, new AbortPolicy) + } + + override def newBoundedQueueFixedThreadPool(nThreads: Int, maxQueueSize: Int, rejectHandler: RejectedExecutionHandler, shortId: String, priority: Int): ThreadPoolExecutor = { + val threadFactory = new CommonThreadFactory(shortId, priority = priority) + //like Executors.newFixedThreadPool + new SinglePhaseInstrumentedThreadPoolExecutor(nThreads, nThreads, 0L, TimeUnit.MILLISECONDS, new ArrayBlockingQueue[Runnable](maxQueueSize), threadFactory, rejectHandler) + } + + override protected def wrapRunnable(r: Runnable, shortId:String): Runnable = () => { + val data = new ThreadProfileData + localData.set(data) + + val profileStart = profiler.snapThread(0) + try r.run finally { + val snap = profiler.snapThread(data.idleNs) + val threadRange = ProfileRange(profileStart, snap, phase, shortId, data.taskCount, Thread.currentThread()) + profiler.completeBackground(threadRange) + } + } + + /** + * data for thread run. Not threadsafe, only written from a single thread + */ + final class ThreadProfileData { + var firstStartNs = 0L + var taskCount = 0 + + var idleNs = 0L + var runningNs = 0L + + var lastStartNs = 0L + var lastEndNs = 0L + } + + val localData = new ThreadLocal[ThreadProfileData] + + private class SinglePhaseInstrumentedThreadPoolExecutor + ( corePoolSize: Int, maximumPoolSize: Int, keepAliveTime: Long, unit: TimeUnit, + workQueue: BlockingQueue[Runnable], threadFactory: ThreadFactory, handler: RejectedExecutionHandler + ) extends ThreadPoolExecutor(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler) { + + override def beforeExecute(t: Thread, r: Runnable): Unit = { + val data = localData.get + data.taskCount += 1 + val now = System.nanoTime() + + if (data.firstStartNs == 0) data.firstStartNs = now + else data.idleNs += now - data.lastEndNs + + data.lastStartNs = now + + super.beforeExecute(t, r) + } + + override def afterExecute(r: Runnable, t: Throwable): Unit = { + val now = System.nanoTime() + val data = localData.get + + data.lastEndNs = now + data.runningNs += now - data.lastStartNs + + super.afterExecute(r, t) + } + + } + } +} diff --git a/compiler/src/dotty/tools/dotc/profile/ExtendedThreadMxBean.java b/compiler/src/dotty/tools/dotc/profile/ExtendedThreadMxBean.java new file mode 100644 index 000000000000..68ae4f148cfd --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/ExtendedThreadMxBean.java @@ -0,0 +1,304 @@ +package dotty.tools.dotc.profile; + +import javax.management.ObjectName; +import java.lang.management.ThreadInfo; +import java.lang.management.ThreadMXBean; +import java.lang.management.ManagementFactory; +import java.lang.reflect.Method; + +@SuppressWarnings("unused") +public abstract class ExtendedThreadMxBean implements ThreadMXBean { + static final ExtendedThreadMxBean proxy; + + static { + ExtendedThreadMxBean local; + ThreadMXBean threadMx = ManagementFactory.getThreadMXBean(); + try { + Class cls = Class.forName("com.sun.management.ThreadMXBean"); + if (cls.isInstance(threadMx)) { + local = new SunThreadMxBean(threadMx); + } else { + local = new OtherThreadMxBean(threadMx); + } + } catch (ClassNotFoundException e) { + local = new OtherThreadMxBean(threadMx); + } + proxy = local; + } + + protected final ThreadMXBean underlying; + + protected ExtendedThreadMxBean(ThreadMXBean underlying) { + this.underlying = underlying; + } + + public abstract long[] getThreadUserTime(long[] longs) throws Exception; + + public abstract boolean isThreadAllocatedMemoryEnabled() throws Exception; + + public abstract void setThreadAllocatedMemoryEnabled(boolean b) throws Exception; + + public abstract long getThreadAllocatedBytes(long l) throws Exception; + + public abstract long[] getThreadAllocatedBytes(long[] longs) throws Exception; + + public abstract boolean isThreadAllocatedMemorySupported() throws Exception; + + public abstract long[] getThreadCpuTime(long[] longs) throws Exception; + //common features from java.lang.management.ThreadMXBean + + @Override + public int getThreadCount() { + return underlying.getThreadCount(); + } + + @Override + public int getPeakThreadCount() { + return underlying.getPeakThreadCount(); + } + + @Override + public long getTotalStartedThreadCount() { + return underlying.getTotalStartedThreadCount(); + } + + @Override + public int getDaemonThreadCount() { + return underlying.getDaemonThreadCount(); + } + + @Override + public long[] getAllThreadIds() { + return underlying.getAllThreadIds(); + } + + @Override + public ThreadInfo getThreadInfo(long id) { + return underlying.getThreadInfo(id); + } + + @Override + public ThreadInfo[] getThreadInfo(long[] ids) { + return underlying.getThreadInfo(ids); + } + + @Override + public ThreadInfo getThreadInfo(long id, int maxDepth) { + return underlying.getThreadInfo(id, maxDepth); + } + + @Override + public ThreadInfo[] getThreadInfo(long[] ids, int maxDepth) { + return underlying.getThreadInfo(ids, maxDepth); + } + + @Override + public boolean isThreadContentionMonitoringSupported() { + return underlying.isThreadContentionMonitoringSupported(); + } + + @Override + public boolean isThreadContentionMonitoringEnabled() { + return underlying.isThreadContentionMonitoringEnabled(); + } + + @Override + public void setThreadContentionMonitoringEnabled(boolean enable) { + underlying.setThreadContentionMonitoringEnabled(enable); + } + + @Override + public long getCurrentThreadCpuTime() { + return underlying.getCurrentThreadCpuTime(); + } + + @Override + public long getCurrentThreadUserTime() { + return underlying.getCurrentThreadUserTime(); + } + + @Override + public long getThreadCpuTime(long id) { + return underlying.getThreadCpuTime(id); + } + + @Override + public long getThreadUserTime(long id) { + return underlying.getThreadUserTime(id); + } + + @Override + public boolean isThreadCpuTimeSupported() { + return underlying.isThreadCpuTimeSupported(); + } + + @Override + public boolean isCurrentThreadCpuTimeSupported() { + return underlying.isCurrentThreadCpuTimeSupported(); + } + + @Override + public boolean isThreadCpuTimeEnabled() { + return underlying.isThreadCpuTimeEnabled(); + } + + @Override + public void setThreadCpuTimeEnabled(boolean enable) { + underlying.setThreadCpuTimeEnabled(enable); + } + + @Override + public long[] findMonitorDeadlockedThreads() { + return underlying.findMonitorDeadlockedThreads(); + } + + @Override + public void resetPeakThreadCount() { + underlying.resetPeakThreadCount(); + } + + @Override + public long[] findDeadlockedThreads() { + return underlying.findDeadlockedThreads(); + } + + @Override + public boolean isObjectMonitorUsageSupported() { + return underlying.isObjectMonitorUsageSupported(); + } + + @Override + public boolean isSynchronizerUsageSupported() { + return underlying.isSynchronizerUsageSupported(); + } + + @Override + public ThreadInfo[] getThreadInfo(long[] ids, boolean lockedMonitors, boolean lockedSynchronizers) { + return underlying.getThreadInfo(ids, lockedMonitors, lockedSynchronizers); + } + + @Override + public ThreadInfo[] dumpAllThreads(boolean lockedMonitors, boolean lockedSynchronizers) { + return underlying.dumpAllThreads(lockedMonitors, lockedSynchronizers); + } + + @Override + public ObjectName getObjectName() { + return underlying.getObjectName(); + } +} + +class OtherThreadMxBean extends ExtendedThreadMxBean { + OtherThreadMxBean(ThreadMXBean underlying) { + super(underlying); + } + + @Override + public long[] getThreadUserTime(long[] longs) throws Exception { + return new long[0]; + } + + @Override + public boolean isThreadAllocatedMemoryEnabled() throws Exception { + return false; + } + + @Override + public void setThreadAllocatedMemoryEnabled(boolean b) throws Exception { + + } + + @Override + public long getThreadAllocatedBytes(long l) throws Exception { + return -1; + } + + @Override + public long[] getThreadAllocatedBytes(long[] longs) throws Exception { + return new long[0]; + } + + @Override + public boolean isThreadAllocatedMemorySupported() throws Exception { + return false; + } + + @Override + public long[] getThreadCpuTime(long[] longs) throws Exception { + return new long[0]; + } + +} + + +class SunThreadMxBean extends ExtendedThreadMxBean { + + private final ThreadMXBean real; + + private final Method getThreadUserTimeMethod; + private final Method isThreadAllocatedMemoryEnabledMethod; + private final Method setThreadAllocatedMemoryEnabledMethod; + private final Method getThreadAllocatedBytesMethod1; + private final Method getThreadAllocatedBytesMethod2; + private final Method isThreadAllocatedMemorySupportedMethod; + private final Method getThreadCpuTimeMethod; + + + public SunThreadMxBean(ThreadMXBean underlying) { + super(underlying); + this.real = underlying; + try { + getThreadUserTimeMethod = real.getClass().getMethod("getThreadUserTime", long[].class); + isThreadAllocatedMemoryEnabledMethod = real.getClass().getMethod("isThreadAllocatedMemoryEnabled"); + setThreadAllocatedMemoryEnabledMethod = real.getClass().getMethod("setThreadAllocatedMemoryEnabled", Boolean.TYPE); + getThreadAllocatedBytesMethod1 = real.getClass().getMethod("getThreadAllocatedBytes", Long.TYPE); + getThreadAllocatedBytesMethod2 = real.getClass().getMethod("getThreadAllocatedBytes", long[].class); + isThreadAllocatedMemorySupportedMethod = real.getClass().getMethod("isThreadAllocatedMemorySupported"); + getThreadCpuTimeMethod = real.getClass().getMethod("getThreadCpuTime", long[].class); + + getThreadUserTimeMethod.setAccessible(true); + isThreadAllocatedMemoryEnabledMethod.setAccessible(true); + setThreadAllocatedMemoryEnabledMethod.setAccessible(true); + getThreadAllocatedBytesMethod1.setAccessible(true); + getThreadAllocatedBytesMethod2.setAccessible(true); + isThreadAllocatedMemorySupportedMethod.setAccessible(true); + getThreadCpuTimeMethod.setAccessible(true); + } catch (Exception e) { + throw new IllegalStateException(e); + } + } + + + public boolean isExtended() { + return true; + } + + public long[] getThreadUserTime(long[] longs) throws Exception { + return (long[]) getThreadUserTimeMethod.invoke(real, longs); + } + + public boolean isThreadAllocatedMemoryEnabled() throws Exception { + return (boolean) isThreadAllocatedMemoryEnabledMethod.invoke(real); + } + + public void setThreadAllocatedMemoryEnabled(boolean b) throws Exception { + setThreadAllocatedMemoryEnabledMethod.invoke(real, b); + } + + public long getThreadAllocatedBytes(long l) throws Exception { + return (long) getThreadAllocatedBytesMethod1.invoke(real,l); + } + + public long[] getThreadAllocatedBytes(long[] longs) throws Exception { + return (long[]) getThreadAllocatedBytesMethod2.invoke(real, longs); + } + + public boolean isThreadAllocatedMemorySupported() throws Exception { + return (boolean) isThreadAllocatedMemorySupportedMethod.invoke(real); + } + + public long[] getThreadCpuTime(long[] longs) throws Exception { + return (long[]) getThreadCpuTimeMethod.invoke(real, longs); + + } +} diff --git a/compiler/src/dotty/tools/dotc/profile/ExternalToolHook.java b/compiler/src/dotty/tools/dotc/profile/ExternalToolHook.java new file mode 100644 index 000000000000..274be637eb8e --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/ExternalToolHook.java @@ -0,0 +1,17 @@ +package dotty.tools.dotc.profile; + +/** + * This is an external tool hook, it allows an external tool such as YourKit or JProfiler to instrument a + * particular phase of the compiler. + * Profilers have hooks to allow starting and stopping profiling on a given method invocation. + * To use add -Yprofile-external-tool (defaults to typer) or -Yprofile-external-tool: (for a specific compiler phase) + * to the compiler flags. + * + * 'before' will be called at the start of the target phase and 'after' at the end, allowing custom profiling to be + * triggered. + */ +public class ExternalToolHook { + private ExternalToolHook() {} + public static void before() {} + public static void after() {} +} diff --git a/compiler/src/dotty/tools/dotc/profile/Profiler.scala b/compiler/src/dotty/tools/dotc/profile/Profiler.scala new file mode 100644 index 000000000000..07612788600c --- /dev/null +++ b/compiler/src/dotty/tools/dotc/profile/Profiler.scala @@ -0,0 +1,262 @@ +package dotty.tools.dotc.profile + +import java.io.{FileWriter, PrintWriter} +import java.lang.management.ManagementFactory +import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicInteger +import javax.management.openmbean.CompositeData +import javax.management.{Notification, NotificationEmitter, NotificationListener} + +import dotty.tools.dotc.core.Phases.Phase +import dotty.tools.dotc.core.Contexts.Context + +object Profiler { + def apply()(implicit ctx: Context): Profiler = + if (!ctx.settings.YprofileEnabled.value) NoOpProfiler + else { + val reporter = if (ctx.settings.YprofileDestination.value != "") + new StreamProfileReporter(new PrintWriter(new FileWriter(ctx.settings.YprofileDestination.value, true))) + else ConsoleProfileReporter + new RealProfiler(reporter) + } + + private[profile] val emptySnap = ProfileSnap(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) { + def updateHeap(heapBytes:Long) = { + copy(heapBytes = heapBytes) + } +} +case class ProfileRange(start: ProfileSnap, end:ProfileSnap, phase:Phase, purpose:String, taskCount:Int, thread:Thread) { + def allocatedBytes = end.allocatedBytes - start.allocatedBytes + + def userNs = end.userTimeNanos - start.userTimeNanos + + def cpuNs = end.cpuTimeNanos - start.cpuTimeNanos + + def idleNs = end.idleTimeNanos - start.idleTimeNanos + + def runNs = end.snapTimeNanos - start.snapTimeNanos + + + private def toMillis(ns: Long) = ns / 1000000.0D + + private def toMegaBytes(bytes: Long) = bytes / 1000000.0D + + + def wallClockTimeMillis = toMillis(end.snapTimeNanos - start.snapTimeNanos) + + def idleTimeMillis = toMillis(end.idleTimeNanos - start.idleTimeNanos) + + def cpuTimeMillis = toMillis(end.cpuTimeNanos - start.cpuTimeNanos) + + def userTimeMillis = toMillis(end.userTimeNanos - start.userTimeNanos) + + def allocatedMB = toMegaBytes(end.allocatedBytes - start.allocatedBytes) + + def retainedHeapMB = toMegaBytes(end.heapBytes - start.heapBytes) +} + +sealed trait Profiler { + + def finished(): Unit + + def beforePhase(phase: Phase): ProfileSnap + + def afterPhase(phase: Phase, profileBefore: ProfileSnap): Unit +} +private [profile] object NoOpProfiler extends Profiler { + + override def beforePhase(phase: Phase): ProfileSnap = Profiler.emptySnap + + override def afterPhase(phase: Phase, profileBefore: ProfileSnap): Unit = () + + override def finished(): Unit = () +} +private [profile] object RealProfiler { + import scala.collection.JavaConverters._ + val runtimeMx = ManagementFactory.getRuntimeMXBean + val memoryMx = ManagementFactory.getMemoryMXBean + val gcMx = ManagementFactory.getGarbageCollectorMXBeans.asScala.toList + val classLoaderMx = ManagementFactory.getClassLoadingMXBean + val compileMx = ManagementFactory.getCompilationMXBean + val threadMx = ExtendedThreadMxBean.proxy + if (threadMx.isThreadCpuTimeSupported) threadMx.setThreadCpuTimeEnabled(true) + private val idGen = new AtomicInteger() +} + +private [profile] class RealProfiler(reporter : ProfileReporter)(implicit ctx: Context) extends Profiler with NotificationListener { + def completeBackground(threadRange: ProfileRange): Unit = { + reporter.reportBackground(this, threadRange) + } + + def outDir = ctx.settings.outputDir.value + + val id = RealProfiler.idGen.incrementAndGet() + RealProfiler.gcMx foreach { + case emitter: NotificationEmitter => emitter.addNotificationListener(this, null, null) + case gc => println(s"Cant connect gcListener to ${gc.getClass}") + } + + private val mainThread = Thread.currentThread() + + private[profile] def snapThread(idleTimeNanos: Long): ProfileSnap = { + import RealProfiler._ + val current = Thread.currentThread() + + ProfileSnap( + threadId = current.getId, + threadName = current.getName, + snapTimeNanos = System.nanoTime(), + idleTimeNanos = idleTimeNanos, + cpuTimeNanos = threadMx.getCurrentThreadCpuTime, + userTimeNanos = threadMx.getCurrentThreadUserTime, + allocatedBytes = threadMx.getThreadAllocatedBytes(Thread.currentThread().getId), + heapBytes = readHeapUsage() + ) + } + private def readHeapUsage() = RealProfiler.memoryMx.getHeapMemoryUsage.getUsed + + private def doGC: Unit = { + System.gc() + System.runFinalization() + } + + reporter.header(this) + + override def finished(): Unit = { + //we may miss a GC event if gc is occurring as we call this + RealProfiler.gcMx foreach { + case emitter: NotificationEmitter => emitter.removeNotificationListener(this) + case gc => + } + reporter.close(this) + } + + + override def handleNotification(notification: Notification, handback: scala.Any): Unit = { + import java.lang.{Long => jLong} + 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 + val action = cd.get("gcAction").toString + val cause = cd.get("gcCause").toString + val info = cd.get("gcInfo").asInstanceOf[CompositeData] + val duration = info.get("duration").asInstanceOf[jLong].longValue() + 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)) + } + } + + override def afterPhase(phase: Phase, snapBefore: ProfileSnap): Unit = { + assert(mainThread eq Thread.currentThread()) + val initialSnap = snapThread(0) + if (ctx.settings.YprofileExternalTool.value.contains(phase.toString)) { + println("Profile hook stop") + ExternalToolHook.after() + } + val finalSnap = if (ctx.settings.YprofileRunGcBetweenPhases.value.contains(phase.toString)) { + doGC + initialSnap.updateHeap(readHeapUsage()) + } else initialSnap + + reporter.reportForeground(this, ProfileRange(snapBefore, finalSnap, phase, "", 0, Thread.currentThread)) + } + + override def beforePhase(phase: Phase): ProfileSnap = { + assert(mainThread eq Thread.currentThread()) + if (ctx.settings.YprofileRunGcBetweenPhases.value.contains(phase.toString)) + doGC + if (ctx.settings.YprofileExternalTool.value.contains(phase.toString)) { + println("Profile hook start") + ExternalToolHook.before() + } + snapThread(0) + } + +} + +case class EventType(name: String) +object EventType { + //main thread with other tasks + val MAIN = EventType("main") + //other task ( background thread) + val BACKGROUND = EventType("background") + //total for compile + val GC = EventType("GC") +} + +sealed trait ProfileReporter { + def reportBackground(profiler: RealProfiler, threadRange: ProfileRange): Unit + def reportForeground(profiler: RealProfiler, threadRange: ProfileRange): Unit + + def reportGc(data: GcEventData): Unit + + def header(profiler: RealProfiler) :Unit + def close(profiler: RealProfiler) :Unit +} + +object ConsoleProfileReporter extends ProfileReporter { + + + override def reportBackground(profiler: RealProfiler, threadRange: ProfileRange): Unit = + // TODO + ??? + override def reportForeground(profiler: RealProfiler, threadRange: ProfileRange): Unit = + // TODO + ??? + + override def close(profiler: RealProfiler): Unit = () + + override def header(profiler: RealProfiler): Unit = { + println(s"Profiler start (${profiler.id}) ${profiler.outDir}") + } + + override def reportGc(data: GcEventData): Unit = { + println(f"Profiler GC reported ${data.gcEndMillis - data.gcStartMillis}ms") + } +} + +class StreamProfileReporter(out:PrintWriter) extends ProfileReporter { + override def header(profiler: RealProfiler): Unit = { + out.println(s"info, ${profiler.id}, version, 2, output, ${profiler.outDir}") + out.println(s"header(main/background),startNs,endNs,runId,phaseId,phaseName,purpose,task-count,threadId,threadName,runNs,idleNs,cpuTimeNs,userTimeNs,allocatedByte,heapSize") + out.println(s"header(GC),startNs,endNs,startMs,endMs,name,action,cause,threads") + } + + override def reportBackground(profiler: RealProfiler, threadRange: ProfileRange): Unit = { + reportCommon(EventType.BACKGROUND, profiler, threadRange) + } + override def reportForeground(profiler: RealProfiler, threadRange: ProfileRange): Unit = { + reportCommon(EventType.MAIN, profiler, threadRange) + } + 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 = { + 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}") + } + + + override def close(profiler: RealProfiler): Unit = { + out.flush + out.close + } +} \ No newline at end of file