More readable logs

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

@@ -73,7 +73,7 @@ final case class ModifiedNames(names: Set[UsedName]) {
     usedName.scopes.asScala.exists(scope => lookupMap.contains(usedName.name -> scope))
 
   override def toString: String =
-    s"ModifiedNames(changes = ${names.mkString(", ")})"
+    s"ModifiedNames(${names.mkString(", ")})"
 }
 object ModifiedNames {
   def compareTwoNameHashes(a: Array[NameHash], b: Array[NameHash]): ModifiedNames = {

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

@@ -76,7 +76,7 @@ object Incremental {
       else
         incremental.log.debug(
           "All initially invalidated classes: " + initialInvClasses + "\n" +
-            "All initially invalidated sources:" + initialInvSources + "\n")
+            "All initially invalidated sources: " + initialInvSources + "\n")
     val analysis = manageClassfiles(options) { classfileManager =>
       incremental.cycle(initialInvClasses,
                         initialInvSources,

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

@@ -47,6 +47,7 @@ private[inc] abstract class IncrementalCommon(val log: sbt.util.Logger, options:
     if (invalidatedRaw.isEmpty && modifiedSrcs.isEmpty)
       previous
     else {
+      debugOuterSection(s"Recompilation cycle #$cycleNum")
       val invalidatedPackageObjects =
         this.invalidatedPackageObjects(invalidatedRaw, previous.relations, previous.apis)
       if (invalidatedPackageObjects.nonEmpty)
@@ -111,15 +112,20 @@ private[inc] abstract class IncrementalCommon(val log: sbt.util.Logger, options:
     val invalidatedSources = classes.flatMap(previous.relations.definesClass) ++ modifiedSrcs
     val invalidatedSourcesForCompilation = expand(invalidatedSources, allSources)
     val pruned = Incremental.prune(invalidatedSourcesForCompilation, previous, classfileManager)
-    debug("********* Pruned: \n" + pruned.relations + "\n*********")
+    debugInnerSection("Pruned")(pruned.relations)
 
     val fresh = doCompile(invalidatedSourcesForCompilation, binaryChanges)
     // For javac as class files are added to classfileManager as they are generated, so
     // this step is redundant. For scalac this is still necessary. TODO: do the same for scalac.
     classfileManager.generated(fresh.relations.allProducts.toArray)
-    debug("********* Fresh: \n" + fresh.relations + "\n*********")
     val merged = pruned ++ fresh //.copy(relations = pruned.relations ++ fresh.relations, apis = pruned.apis ++ fresh.apis)
-    debug("********* Merged: \n" + merged.relations + "\n*********")
+
+    if (fresh.relations == merged.relations) {
+      debugInnerSection("Fresh == Merged")(fresh.relations)
+    } else {
+      debugInnerSection("Fresh")(fresh.relations)
+      debugInnerSection("Merged")(merged.relations)
+    }
     (merged, invalidatedSourcesForCompilation)
   }
 
@@ -279,7 +285,7 @@ private[inc] abstract class IncrementalCommon(val log: sbt.util.Logger, options:
     val inv: Set[String] = propagated ++ dups
     val newlyInvalidated = (inv -- recompiledClasses) ++ dups
     log.debug(
-      "All newly invalidated classes after taking into account (previously) recompiled classes:" + newlyInvalidated)
+      "All newly invalidated classes after taking into account (previously) recompiled classes: " + newlyInvalidated)
     if (newlyInvalidated.isEmpty) Set.empty else inv
   }
 
@@ -333,25 +339,42 @@ private[inc] abstract class IncrementalCommon(val log: sbt.util.Logger, options:
     val allInvalidatedClasses = invalidatedClasses ++ byExtSrcDep
     val allInvalidatedSourcefiles = addedSrcs ++ modifiedSrcs ++ byProduct ++ byBinaryDep
 
+    debugOuterSection(s"Initial invalidation")
     if (previous.allSources.isEmpty)
       log.debug("Full compilation, no sources in previous analysis.")
     else if (allInvalidatedClasses.isEmpty && allInvalidatedSourcefiles.isEmpty)
       log.debug("No changes")
-    else
+    else {
+      def color(s: String) = Console.YELLOW + s + Console.RESET
       log.debug(
-        "\nInitial source changes: \n\tremoved:" + removedSrcs + "\n\tadded: " + addedSrcs + "\n\tmodified: " + modifiedSrcs +
-          "\nInvalidated products: " + changes.removedProducts +
-          "\nExternal API changes: " + changes.external +
-          "\nModified binary dependencies: " + changes.binaryDeps +
-          "\nInitial directly invalidated classes: " + invalidatedClasses +
-          "\n\nSources indirectly invalidated by:" +
-          "\n\tproduct: " + byProduct +
-          "\n\tbinary dep: " + byBinaryDep +
-          "\n\texternal source: " + byExtSrcDep
+        s"""
+           |${color("Initial source changes")}:
+           |  ${color("removed")}: ${showSet(removedSrcs, baseIndent = "  ")}
+           |  ${color("added")}: ${showSet(addedSrcs, baseIndent = "  ")}
+           |  ${color("modified")}: ${showSet(modifiedSrcs, baseIndent = "  ")}
+           |${color("Invalidated products")}: ${showSet(changes.removedProducts)}
+           |${color("External API changes")}: ${changes.external}
+           |${color("Modified binary dependencies")}: ${changes.binaryDeps}
+           |${color("Initial directly invalidated classes")}: $invalidatedClasses
+           |
+           |${color("Sources indirectly invalidated by")}:
+           |  ${color("product")}: ${showSet(byProduct, baseIndent = "  ")}
+           |  ${color("binary dep")}: ${showSet(byBinaryDep, baseIndent = "  ")}
+           |  ${color("external source")}: ${showSet(byExtSrcDep, baseIndent = "  ")}""".stripMargin
       )
+    }
 
     (allInvalidatedClasses, allInvalidatedSourcefiles)
   }
+
+  private def showSet[A](s: Set[A], baseIndent: String = ""): String = {
+    if (s.isEmpty) {
+      "[]"
+    } else {
+      s.map(baseIndent + "  " + _.toString).mkString("[\n", ",\n", "\n" + baseIndent + "]")
+    }
+  }
+
   private[this] def checkAbsolute(addedSources: List[File]): Unit =
     if (addedSources.nonEmpty) {
       addedSources.filterNot(_.isAbsolute) match {
@@ -501,4 +524,15 @@ private[inc] abstract class IncrementalCommon(val log: sbt.util.Logger, options:
     }
     xs.toSet
   }
+
+  private[this] def debugOuterSection(header: String): Unit = {
+    import Console._
+    log.debug(s"$GREEN*************************** $header$RESET")
+  }
+
+  private[this] def debugInnerSection(header: String)(content: => Any): Unit = {
+    import Console._
+    debug(s"$CYAN************* $header:$RESET\n$content\n$CYAN************* (end of $header)$RESET")
+  }
+
 }

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

@@ -68,7 +68,7 @@ private final class IncrementalNameHashing(log: sbt.util.Logger, options: IncOpt
                                               externalAPIChange: APIChange,
                                               isScalaClass: String => Boolean): Set[String] = {
     val modifiedBinaryClassName = externalAPIChange.modifiedClass
-    val invalidationReason = memberRefInvalidator.invalidationReason(externalAPIChange)
+    val invalidationReason = memberRefInvalidator.invalidationReason(externalAPIChange).capitalize
     log.debug(
       s"$invalidationReason\nAll member reference dependencies will be considered within this context.")
     // Propagate inheritance dependencies transitively.
@@ -136,20 +136,17 @@ private final class IncrementalNameHashing(log: sbt.util.Logger, options: IncOpt
     def debugMessage: String = {
       if (all.isEmpty) s"Change $change does not affect any class."
       else {
-        val byTransitiveInheritance =
-          if (transitiveInheritance.nonEmpty) s"by transitive inheritance: $transitiveInheritance"
-          else ""
-        val byLocalInheritance =
-          if (localInheritance.nonEmpty) s"by local inheritance: $localInheritance" else ""
-        val byMemberRef =
-          if (memberRef.nonEmpty) s"by member reference: $memberRef" else ""
-
-        s"""Change $change invalidates ${all.size} classes due to ${memberRefInvalidator
-             .invalidationReason(change)}
-           |\t> $byTransitiveInheritance
-           |\t> $byLocalInheritance
-           |\t> $byMemberRef
-        """.stripMargin
+        def by(reason: String, classes: Set[String]) = {
+          if (classes.isEmpty) ""
+          else {
+            s"\tby $reason: ${classes.mkString(", ")}\n"
+          }
+        }
+
+        s"${all.size} classes were invalidated due to ${memberRefInvalidator.invalidationReason(change)}\n" +
+          by("transitive inheritance", transitiveInheritance) +
+          by("local inheritance", localInheritance) +
+          by("member reference", memberRef)
       }
     }
 

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

@@ -67,17 +67,15 @@ private[inc] class MemberRefInvalidator(log: Logger, logRecompileOnMacro: Boolea
 
   def invalidationReason(apiChange: APIChange): String = apiChange match {
     case TraitPrivateMembersModified(modifiedClass) =>
-      s"The private signature of trait ${modifiedClass} changed."
+      s"the private signature of trait $modifiedClass changed."
     case APIChangeDueToMacroDefinition(modifiedSrcFile) =>
-      s"The $modifiedSrcFile source file declares a macro."
+      s"the $modifiedSrcFile source file declares a macro."
     case NamesChange(modifiedClass, modifiedNames) =>
       modifiedNames.in(UseScope.Implicit) match {
         case changedImplicits if changedImplicits.isEmpty =>
-          s"""|The $modifiedClass has the following regular definitions changed:
-              |\t${modifiedNames.names.mkString(", ")}.""".stripMargin
+          s"the $modifiedClass has the following regular definitions changed: ${modifiedNames.names}"
         case changedImplicits =>
-          s"""|The $modifiedClass has the following implicit definitions changed:
-              |\t${changedImplicits.mkString(", ")}.""".stripMargin
+          s"""the $modifiedClass has the following implicit definitions changed: $changedImplicits""".stripMargin
       }
   }
 

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

@@ -509,12 +509,20 @@ private abstract class MRelationsCommon(
   /** Making large Relations a little readable. */
   private val userDir = sys.props("user.dir").stripSuffix("/") + "/"
   private def nocwd(s: String) = s stripPrefix userDir
-  private def line_s(kv: (Any, Any)) =
-    "    " + nocwd("" + kv._1) + " -> " + nocwd("" + kv._2) + "\n"
-  protected def relation_s(r: Relation[_, _]) = (
-    if (r.forwardMap.isEmpty) "Relation [ ]"
-    else (r.all.toSeq.map(line_s).sorted) mkString ("Relation [\n", "", "]")
-  )
+  private def formatAsLines(kvs: Seq[(Any, Any)], indentation: String): Seq[String] = {
+    val stringified = kvs.map { case (k, v) => nocwd(k.toString) -> nocwd(v.toString) }
+    val longestKey = stringified.map(_._1.length).max
+    stringified.map {
+      case (k, v) =>
+        indentation + "  " + k.padTo(longestKey, ' ') + " -> " + v + "\n"
+    }
+  }
+  protected def relation_s(r: Relation[_, _], indentation: String): String = {
+    if (r.forwardMap.isEmpty) "[]"
+    else
+      formatAsLines(r.all.toSeq, indentation).sorted.mkString("[\n", "", indentation + "]")
+  }
+  protected def relation_s(r: Relation[_, _]): String = relation_s(r, "  ")
 }
 
 /**
@@ -663,22 +671,26 @@ private class MRelationsNameHashing(
     (srcProd :: libraryDep :: libraryClassName :: memberRef :: inheritance :: classes :: Nil).hashCode
 
   override def toString: String = {
-    val internalDepsStr = (internalDependencies.dependencies map {
-      case (k, vs) => k + " " + relation_s(vs)
-    }).mkString("\n    ", "\n    ", "")
-    val externalDepsStr = (externalDependencies.dependencies map {
-      case (k, vs) => k + " " + relation_s(vs)
-    }).mkString("\n    ", "\n    ", "")
+    def color(s: String) = Console.YELLOW + s + Console.RESET
+    def nestedRelation(deps: Map[_, Relation[_, _]]): String = {
+      if (deps.isEmpty) "[]"
+      else {
+        val indentation = "    "
+        deps
+          .map { case (k, vs) => color(k.toString) + ": " + relation_s(vs, indentation) }
+          .mkString("\n" + indentation, "\n" + indentation, "")
+      }
+    }
     s"""
     |Relations (with name hashing enabled):
-    |  products: ${relation_s(srcProd)}
-    |  library deps: ${relation_s(libraryDep)}
-    |  library class names: ${relation_s(libraryClassName)}
-    |  internalDependencies: $internalDepsStr
-    |  externalDependencies: $externalDepsStr
-    |  class names: ${relation_s(classes)}
-    |  used names: ${relation_s(names)}
-    |  product class names: ${relation_s(productClassName)}
+    |  ${color("products")}: ${relation_s(srcProd)}
+    |  ${color("library dependencies")}: ${relation_s(libraryDep)}
+    |  ${color("library class names")}: ${relation_s(libraryClassName)}
+    |  ${color("internal dependencies")}: ${nestedRelation(internalDependencies.dependencies)}
+    |  ${color("external dependencies")}: ${nestedRelation(externalDependencies.dependencies)}
+    |  ${color("class names")}: ${relation_s(classes)}
+    |  ${color("used names")}: ${relation_s(names)}
+    |  ${color("product class names")}: ${relation_s(productClassName)}
     """.trim.stripMargin
   }
 }

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

@@ -11,7 +11,13 @@ import java.util
 
 import xsbti.UseScope
 
-case class UsedName private (name: String, scopes: util.EnumSet[UseScope])
+case class UsedName private (name: String, scopes: util.EnumSet[UseScope]) {
+
+  override def toString: String = {
+    val formattedScopes = if (scopes == UsedName.DefaultScope) "" else " " + scopes
+    name + formattedScopes
+  }
+}
 
 object UsedName {
 
@@ -25,4 +31,7 @@ object UsedName {
   private def escapeControlChars(name: String) = {
     name.replaceAllLiterally("\n", "\u26680A")
   }
+
+  private val DefaultScope = java.util.EnumSet.of(UseScope.Default)
+
 }