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

Macro data seems to be counted incorrectly under show-profiles #97

Open
DSlug opened this issue Jan 24, 2024 · 2 comments
Open

Macro data seems to be counted incorrectly under show-profiles #97

DSlug opened this issue Jan 24, 2024 · 2 comments
Labels
bug scalac-profiling Relates to the compiler plugin

Comments

@DSlug
Copy link
Contributor

DSlug commented Jan 24, 2024

expandedNodes and expansionNanos are always 0 in the output generated when the show-profiles flag is enabled.

Example code:

import io.circe.generic.semiauto._
import io.circe.generic.auto._
object Main {
  case class T(f1: Either[List[List[List[Int]]],Option[String]])
  def main(args: Array[String]): Unit = deriveCodec[T]
}

Output:

[info] time spent in macroExpand     : 180 spans, ()344.558ms (88.6%)
[info] Macro data per call-site:
[info] Map(
[info]   NoPosition -> MacroInfo(expandedMacros = 6, expandedNodes = 0, expansionNanos = 0L),
[info]   source-testproj/src/main/scala/Main.scala,line-7,offset=198 -> MacroInfo(
[info]     expandedMacros = 58,
[info]     expandedNodes = 0,
[info]     expansionNanos = 0L
[info]   )
[info] )
[info] Macro data per file:
[info] HashMap(
[info]   Main.scala -> MacroInfo(expandedMacros = 58, expandedNodes = 0, expansionNanos = 0L),
[info]   <no source file> -> MacroInfo(expandedMacros = 6, expandedNodes = 0, expansionNanos = 0L)
[info] )
[info] Macro data in total:
[info] MacroInfo(expandedMacros = 64, expandedNodes = 0, expansionNanos = 0L)

This is occurring in both 2.12 and 2.13 for me.

@danicheg danicheg added bug scalac-profiling Relates to the compiler plugin labels Jan 25, 2024
@DSlug
Copy link
Contributor Author

DSlug commented Jan 26, 2024

Did a bit of digging to see if I could find a cause, ProfilingImpl contains this bit of code:

val treeSize = 0 // macroInfo.expandedNodes + guessTreeSize(expanded)

// Use 0L for the timer because it will be filled in by the caller `apply`
macroInfos.put(callSitePos, MacroInfo(expandedMacros, treeSize, 0L))
expanded

... But the timer never actually gets filled.

pluginsMacroExpand used to contain a function that updated the timers, but it got removed in 6000f5e:

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
  }
}

@danicheg danicheg added this to the v1.1.0-RC3 milestone Feb 18, 2024
danicheg added a commit to danicheg/scalac-profiling that referenced this issue Mar 16, 2024
danicheg added a commit to danicheg/scalac-profiling that referenced this issue Jul 6, 2024
@danicheg danicheg removed this from the v1.1.0-RC4 milestone Jul 8, 2024
@danicheg
Copy link
Collaborator

As I wrote in #133, expansionNanoss should become more plausible, but the issue with the blank expandedNodess is still present. That's why I think the current issue should be open. Disregarding the matter of whether expandedNodes is required to have in general.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug scalac-profiling Relates to the compiler plugin
Projects
None yet
2 participants