Add profiling invalidation utils (zprof)

zprof is the name I've chosen for this small profiler (or tracker if you
will) of the invalidation logic. The profiled data is formalized in an
internal format that is not supposed to be used by normal users, but
rather by us (Zinc) and related tools (Bloop).

The current profiled data exposes details of how the incremental
compiler works internally and how it invalidates classes. This is the
realization of an idea I registered here: sbt#550

With this idea, this data will not only be useful for debugging but for
providing an automatic way of reporting bugs in Zinc. The infrastructure
is far from finished but it's already in a usable state for libraries
that depend on Zinc directly and have direct access to `Incremental`.

By default, no profiler is used. Only people that change the profiler
argument for `Incremental.compile` will be able to get the run profiles.

Author: jvican

build.sbt

@@ -243,6 +243,7 @@ lazy val zincCore = (project in internalPath / "zinc-core")
     name := "zinc Core",
     compileOrder := sbt.CompileOrder.Mixed,
     mimaSettings,
+    PB.targets in Compile := List(scalapb.gen() -> (sourceManaged in Compile).value),
   )
   .configure(addSbtIO, addSbtUtilLogging, addSbtUtilRelation)
 

internal/zinc-core/src/main/protobuf/zprof.proto

@@ -0,0 +1,68 @@
+syntax = "proto3";
+
+package sbt.internal.inc;
+
+///////////////////////////////////////////////////////////////////////////////////////////////
+///////////////////////////////////////// ZINC PROF ///////////////////////////////////////////
+///////////////////////////////////////////////////////////////////////////////////////////////
+
+message Profile {
+    repeated ZincRun runs = 1;
+    repeated string string_table = 2;
+}
+
+message ZincRun {
+    InitialChanges initial = 1;
+    repeated CycleInvalidation cycles = 3;
+}
+
+message CycleInvalidation {
+    repeated int64 invalidated = 1;
+    repeated int64 invalidatedByPackageObjects = 2;
+    repeated int64 initialSources = 3;
+    repeated int64 invalidatedSources = 4;
+    repeated int64 recompiledClasses = 5;
+
+    int64 startTimeNanos = 6; // Start time of compilation (UTC) as nanoseconds past the epoch
+    int64 compilationDurationNanos = 7; // Duration of the compilation profile in nanoseconds
+    repeated ApiChange changesAfterRecompilation = 8;
+
+    repeated InvalidationEvent events = 9;
+    repeated int64 nextInvalidations = 10;
+    bool shouldCompileIncrementally = 11;
+}
+
+message InvalidationEvent {
+    string kind = 1;
+    repeated int64 inputs = 2;
+    repeated int64 outputs = 3;
+    string reason = 4;
+}
+
+message Changes {
+    repeated int64 added = 1;
+    repeated int64 removed = 2;
+    repeated int64 modified = 3;
+}
+
+message ApiChange {
+    int64 modifiedClass = 1;
+    string reason = 2;
+    repeated UsedName usedNames = 3; // Can be empty if the change is not related to names
+}
+
+message InitialChanges {
+    Changes changes = 1;
+    repeated int64 removedProducts = 2;
+    repeated int64 binaryDependencies = 3;
+    repeated ApiChange externalChanges = 4;
+}
+
+message UsedName {
+    int64 name = 1;
+    repeated Scope scopes = 2;
+}
+
+message Scope {
+    int64 kind = 1;
+}

internal/zinc-core/src/main/scala/sbt/internal/inc/Incremental.scala

@@ -14,10 +14,10 @@ import java.io.File
 import sbt.util.{ Level, Logger }
 import xsbti.compile.analysis.{ ReadStamps, Stamp => XStamp }
 import xsbti.compile.{
-  ClassFileManager => XClassFileManager,
   CompileAnalysis,
   DependencyChanges,
-  IncOptions
+  IncOptions,
+  ClassFileManager => XClassFileManager
 }
 
 /**
@@ -46,6 +46,7 @@ object Incremental {
    * @param callbackBuilder The builder that builds callback where we report dependency issues.
    * @param log  The log where we write debugging information
    * @param options  Incremental compilation options
+   * @param profiler An implementation of an invalidation profiler, empty by default.
    * @param equivS  The means of testing whether two "Stamps" are the same.
    * @return
    *         A flag of whether or not compilation completed successfully, and the resulting dependency analysis object.
@@ -58,11 +59,12 @@ object Incremental {
       compile: (Set[File], DependencyChanges, xsbti.AnalysisCallback, XClassFileManager) => Unit,
       callbackBuilder: AnalysisCallback.Builder,
       log: sbt.util.Logger,
-      options: IncOptions
+      options: IncOptions,
+      profiler: InvalidationProfiler = InvalidationProfiler.empty
   )(implicit equivS: Equiv[XStamp]): (Boolean, Analysis) = {
     val previous = previous0 match { case a: Analysis => a }
-    val incremental: IncrementalCommon =
-      new IncrementalNameHashing(log, options)
+    val runProfiler = profiler.profileRun
+    val incremental: IncrementalCommon = new IncrementalNameHashing(log, options, runProfiler)
     val initialChanges = incremental.detectInitialChanges(sources, previous, current, lookup)
     val binaryChanges = new DependencyChanges {
       val modifiedBinaries = initialChanges.binaryDeps.toArray

internal/zinc-core/src/main/scala/sbt/internal/inc/IncrementalCommon.scala

@@ -31,7 +31,11 @@ import scala.annotation.tailrec
  * @param log An instance of a logger.
  * @param options An instance of incremental compiler options.
  */
-private[inc] abstract class IncrementalCommon(val log: Logger, options: IncOptions) {
+private[inc] abstract class IncrementalCommon(
+    val log: Logger,
+    options: IncOptions,
+    profiler: RunProfiler
+) extends InvalidationProfilerUtils {
   // Work around bugs in classpath handling such as the "currently" problematic -javabootclasspath
   private[this] def enableShallowLookup: Boolean =
     java.lang.Boolean.getBoolean("xsbt.skip.cp.lookup")
@@ -81,11 +85,11 @@ private[inc] abstract class IncrementalCommon(val log: Logger, options: IncOptio
       // Computes which source files are mapped to the invalidated classes and recompile them
       val invalidatedSources =
         mapInvalidationsToSources(classesToRecompile, initialChangedSources, allSources, previous)
-      val (current, recompiledRecently) =
+      val current =
         recompileClasses(invalidatedSources, binaryChanges, previous, doCompile, classfileManager)
 
       // Return immediate analysis as all sources have been recompiled
-      if (recompiledRecently == allSources) current
+      if (invalidatedSources == allSources) current
       else {
         val recompiledClasses: Set[String] = {
           // Represents classes detected as changed externally and internally (by a previous cycle)
@@ -107,6 +111,18 @@ private[inc] abstract class IncrementalCommon(val log: Logger, options: IncOptio
         )
 
         val continue = lookup.shouldDoIncrementalCompilation(nextInvalidations, current)
+
+        profiler.registerCycle(
+          invalidatedClasses,
+          invalidatedByPackageObjects,
+          initialChangedSources,
+          invalidatedSources,
+          recompiledClasses,
+          newApiChanges,
+          nextInvalidations,
+          continue
+        )
+
         cycle(
           if (continue) nextInvalidations else Set.empty,
           Set.empty,
@@ -147,20 +163,20 @@ private[inc] abstract class IncrementalCommon(val log: Logger, options: IncOptio
       previous: Analysis,
       doCompile: (Set[File], DependencyChanges) => Analysis,
       classfileManager: XClassFileManager
-  ): (Analysis, Set[File]) = {
+  ): Analysis = {
     val pruned =
       IncrementalCommon.pruneClassFilesOfInvalidations(sources, previous, classfileManager)
     debug("********* Pruned: \n" + pruned.relations + "\n*********")
     val fresh = doCompile(sources, binaryChanges)
     debug("********* Fresh: \n" + fresh.relations + "\n*********")
-    val merged = pruned ++ fresh
 
     /* This is required for both scala compilation and forked java compilation, despite
      *  being redundant for the most common Java compilation (using the local compiler). */
     classfileManager.generated(fresh.relations.allProducts.toArray)
 
+    val merged = pruned ++ fresh
     debug("********* Merged: \n" + merged.relations + "\n*********")
-    (merged, sources)
+    merged
   }
 
   /**
@@ -258,7 +274,9 @@ private[inc] abstract class IncrementalCommon(val log: Logger, options: IncOptio
       else incrementalExternalChanges
     }
 
-    InitialChanges(sourceChanges, removedProducts, changedBinaries, externalApiChanges)
+    val init = InitialChanges(sourceChanges, removedProducts, changedBinaries, externalApiChanges)
+    profiler.registerInitial(init)
+    init
   }
 
   /**

internal/zinc-core/src/main/scala/sbt/internal/inc/IncrementalNameHashing.scala

@@ -24,8 +24,11 @@ import xsbt.api.SameAPI
  * See [[MemberRefInvalidator]] for more information on how the name heuristics work to invalidate
  * member references.
  */
-private[inc] class IncrementalNameHashingCommon(log: Logger, options: IncOptions)
-    extends IncrementalCommon(log, options) {
+private[inc] class IncrementalNameHashingCommon(
+    log: Logger,
+    options: IncOptions,
+    profiler: RunProfiler
+) extends IncrementalCommon(log, options, profiler) {
   import IncrementalCommon.transitiveDeps
 
   private val memberRefInvalidator = new MemberRefInvalidator(log, options.logRecompileOnMacro())
@@ -142,13 +145,32 @@ private[inc] class IncrementalNameHashingCommon(log: Logger, options: IncOptions
 
     val modifiedClass = change.modifiedClass
     val transitiveInheritance = invalidateByInheritance(relations, modifiedClass)
+    profiler.registerEvent(
+      zprof.InvalidationEvent.InheritanceKind,
+      List(modifiedClass),
+      transitiveInheritance,
+      s"The invalidated class names inherit directly or transitively on ${modifiedClass}."
+    )
+
     val localInheritance =
       transitiveInheritance.flatMap(invalidateByLocalInheritance(relations, _))
+    profiler.registerEvent(
+      zprof.InvalidationEvent.LocalInheritanceKind,
+      transitiveInheritance,
+      localInheritance,
+      s"The invalidated class names inherit (via local inheritance) directly or transitively on ${modifiedClass}."
+    )
 
     val memberRefSrcDeps = relations.memberRef.internal
     val memberRefInvalidation =
       memberRefInvalidator.get(memberRefSrcDeps, relations.names, change, isScalaClass)
     val memberRef = transitiveInheritance flatMap memberRefInvalidation
+    profiler.registerEvent(
+      zprof.InvalidationEvent.MemberReferenceKind,
+      transitiveInheritance,
+      memberRef,
+      s"The invalidated class names refer directly or transitively to ${modifiedClass}."
+    )
     val all = transitiveInheritance ++ localInheritance ++ memberRef
 
     def debugMessage: String = {
@@ -182,5 +204,5 @@ private[inc] class IncrementalNameHashingCommon(log: Logger, options: IncOptions
   ): Set[String] = relations.memberRef.internal.reverse(className)
 }
 
-private final class IncrementalNameHashing(log: Logger, options: IncOptions)
-    extends IncrementalNameHashingCommon(log, options)
+private final class IncrementalNameHashing(log: Logger, options: IncOptions, profiler: RunProfiler)
+    extends IncrementalNameHashingCommon(log, options, profiler)