From 5af7f4b0bdae45c181e35b5124729dc13a316878 Mon Sep 17 00:00:00 2001 From: DSlug Date: Tue, 20 Feb 2024 20:13:15 +0100 Subject: [PATCH 1/2] re-add code tracking macroExpand times --- .../epfl/scala/profilers/ProfilingImpl.scala | 37 ++++++++++++++----- 1 file changed, 27 insertions(+), 10 deletions(-) diff --git a/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala b/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala index 3a857bc..9ec677d 100644 --- a/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala +++ b/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala @@ -80,9 +80,6 @@ final class ProfilingImpl[G <: Global]( import ProfilingMacroPlugin.macroInfos // , repeatedTrees} val perCallSite = macroInfos.toMap val perFile = groupPerFile(perCallSite)(MacroInfo.Empty, _ + _) - .map { - case (sf, mi) => sf -> mi.copy(expansionNanos = toMillis(mi.expansionNanos)) - } val inTotal = MacroInfo.aggregate(perFile.valuesIterator) /* val repeated = repeatedTrees.toMap.valuesIterator @@ -91,9 +88,7 @@ final class ProfilingImpl[G <: Global]( .toMap*/ // perFile and inTotal are already converted to millis - val callSiteNanos = perCallSite.map { - case (pos, mi) => pos -> mi.copy(expansionNanos = toMillis(mi.expansionNanos)) - } + val callSiteNanos = perCallSite MacroProfiler(callSiteNanos, perFile, inTotal, Map.empty) // repeated) } @@ -537,9 +532,23 @@ final class ProfilingImpl[G <: Global]( macroCounter = macroCounter + 1 object expander extends analyzer.DefMacroExpander(t, expandee, md, pt) { + private var alreadyTracking: Boolean = false /** The default method that expands all macros. */ - override def apply(desugared: Tree): Tree = { + override def apply(desugared: Tree): Tree = { + def updateExpansionTime(desugared: Tree, start: statistics.TimerSnapshot): Unit = { + statistics.stopTimer(preciseMacroTimer, start) + val (nanos0, _) = start + val timeNanos = (preciseMacroTimer.nanos - nanos0) + val callSitePos = desugared.pos + // Those that are not present failed to expand + macroInfos.get(callSitePos).foreach { found => + val updatedInfo = found.copy(expansionNanos = timeNanos) + macroInfos(callSitePos) = updatedInfo + } + } + val shouldTrack = statistics.enabled && !alreadyTracking + val prevData = macrosStack.headOption.map { prev => macroIdsToTimers.getOrElse( prev.id, @@ -556,7 +565,10 @@ final class ProfilingImpl[G <: Global]( val searchPrefix = s" macro ${macroId}" val macroTimer = registerTyperTimerFor(searchPrefix) macroIdsToTimers += ((macroId, macroTimer)) - val start = statistics.startTimer(macroTimer) + val start = { + alreadyTracking = true + statistics.startTimer(macroTimer) + } val entry = MacroEntry(macroId, pt, start, None) @@ -573,6 +585,11 @@ final class ProfilingImpl[G <: Global]( macrosStack = entry :: macrosStack try super.apply(desugared) finally { + if (shouldTrack) { + alreadyTracking = false + updateExpansionTime(desugared, start) + } + val children = macroChildren.getOrElse(macroId, Nil) if (config.generateMacroFlamegraph) { // Complete stack names of triggered implicit searches @@ -714,9 +731,9 @@ final class ProfilingImpl[G <: Global]( trait ProfilingStats { val global: Global - import global.statistics.{newSubCounter, macroExpandCount, implicitSearchCount} + import global.statistics.{newSubCounter, macroExpandCount, implicitSearchCount, newTimer} macroExpandCount.children.clear() - + final val preciseMacroTimer = newTimer("precise time in macroExpand") final val failedMacros = newSubCounter(" of which failed macros", macroExpandCount) final val delayedMacros = newSubCounter(" of which delayed macros", macroExpandCount) final val suppressedMacros = newSubCounter(" of which suppressed macros", macroExpandCount) From 5d3c9b4a214231684764bbc92b3e0704fee7f1a9 Mon Sep 17 00:00:00 2001 From: danicheg Date: Sat, 13 Jul 2024 15:44:46 +0400 Subject: [PATCH 2/2] Scalafmt --- .../epfl/scala/profilers/ProfilingImpl.scala | 22 +++++++++---------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala b/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala index 9ec677d..77f7411 100644 --- a/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala +++ b/plugin/src/main/scala/ch/epfl/scala/profilers/ProfilingImpl.scala @@ -535,18 +535,18 @@ final class ProfilingImpl[G <: Global]( private var alreadyTracking: Boolean = false /** The default method that expands all macros. */ - override def apply(desugared: Tree): Tree = { - def updateExpansionTime(desugared: Tree, start: statistics.TimerSnapshot): Unit = { - statistics.stopTimer(preciseMacroTimer, start) - val (nanos0, _) = start - val timeNanos = (preciseMacroTimer.nanos - nanos0) - val callSitePos = desugared.pos - // Those that are not present failed to expand - macroInfos.get(callSitePos).foreach { found => - val updatedInfo = found.copy(expansionNanos = timeNanos) - macroInfos(callSitePos) = updatedInfo + override def apply(desugared: Tree): Tree = { + def updateExpansionTime(desugared: Tree, start: statistics.TimerSnapshot): Unit = { + statistics.stopTimer(preciseMacroTimer, start) + val (nanos0, _) = start + val timeNanos = (preciseMacroTimer.nanos - nanos0) + val callSitePos = desugared.pos + // Those that are not present failed to expand + macroInfos.get(callSitePos).foreach { found => + val updatedInfo = found.copy(expansionNanos = timeNanos) + macroInfos(callSitePos) = updatedInfo + } } - } val shouldTrack = statistics.enabled && !alreadyTracking val prevData = macrosStack.headOption.map { prev =>