Mainstreaming phase awareness.

As I peer into various longstanding crashes involving specialization,
mixin composition, and super calls, I find a very common reason for
logic to go wrong is ignoring or misusing atPhase. This is hardly
surprising given how much of a secret black art the whole process of
atPhase-ing is. I predict with some confidence that at least half the
calls to atPhase in the compiler are at best unnecessary and more likely
wrong; similarly, we are missing at least as many calls in other places.

Herein we find the following:

1) log messages now include not only the current "at" phase, which
in isolation was very confusing because it means what is logged is
dependent on the arbitrary jumps performed by atPhase, but the entire
"phase stack", anchored by the "global phase".

The leftmost phase is the global phase, the one set in Global which
proceeds in a predictable fashion from parser to terminal. That's the
one we usually mean when we talk about during which phase something
happens. The others (prefixed with an arrow) are calls to atPhase which
have not yet returned.

  // example, assuming we've given -Ylog:expl
  scala> atPhase(currentRun.explicitouterPhase)(log("hi mom"))
  [log terminal(->typer ->explicitouter)] hi mom

2) A message will be logged if either the globalPhase matches,
or the current "at" phase does.  So -Ylog:erasure will log all the
messages from the phase we think of as erasure, and also all those
from any phase run inside of atPhase(erasurePhase) { ... }
(except for times when that block uses atPhase to alter the
phase yet again - it only looks at the top of the atPhase stack.)

  // example
  % scalac -Ydebug -Ylog:refchecks foo.scala

  [log refchecks] overriding-pairs? method size in trait TraversableOnce ...
  [log mixin(->refchecks)] rebindsuper trait GenTraversable <none> <notype> false

3) A number of debug/power oriented functions.  All of these
limit their results to phase transitions during which some change took
place, as measured by the result of `op`, compared with ==.

  def afterEachPhase[T](op: => T): List[(Phase, T)]
  def changesAfterEachPhase[T](op: => List[T]): List[ChangeAfterPhase[T]]

  def logAfterEveryPhase[T](msg: String)(op: => T)
  def describeAfterEachPhase[T](op: => T): List[String]
  def describeAfterEveryPhase[T](op: => T): String
  def printAfterEachPhase[T](op: => T): Unit

Some examples:

  scala> printAfterEachPhase(ListClass.info.members.size)
    [after  1/parser      ] 219
    [after 11/tailcalls   ] 220
    [after 12/specialize  ] 322
    [after 14/erasure     ] 361
    [after 18/flatten     ] 357

  scala> printAfterEachPhase(termMember(PredefModule, "implicitly").defString)
    [after  1/parser      ] def implicitly[T](implicit e: T): T
    [after 10/uncurry     ] def implicitly[T](e: T): T
    [after 14/erasure     ] def implicitly(e: Object): Object

Try this at home:

  scala> changesAfterEachPhase(ListClass.info.nonPrivateMembers map (_.defString)) foreach println

1 files changed, 62 insertions, 2 deletions

diff --git a/src/compiler/scala/tools/nsc/Global.scala b/src/compiler/scala/tools/nsc/Global.scala
index 4493188b31..ca5604c828 100644
--- a/src/compiler/scala/tools/nsc/Global.scala
+++ b/src/compiler/scala/tools/nsc/Global.scala
@@ -213,10 +213,23 @@ class Global(var currentSettings: Settings, var reporter: Reporter) extends Symb
   def informTime(msg: String, start: Long) = informProgress(elapsedMessage(msg, start))
 
   def logError(msg: String, t: Throwable): Unit = ()
+
+  private def atPhaseStackMessage = atPhaseStack match {
+    case Nil    => ""
+    case ps     => ps.reverseMap("->" + _).mkString("(", " ", ")")
+  }
+  private def shouldLogAtThisPhase = (
+       (settings.log.isSetByUser)
+    && ((settings.log containsPhase globalPhase) || (settings.log containsPhase phase))
+  )
+
+  def logAfterEveryPhase[T](msg: String)(op: => T) {
+    log("Running operation '%s' after every phase.\n" + describeAfterEveryPhase(op))
+  }
   // Over 200 closure objects are eliminated by inlining this.
   @inline final def log(msg: => AnyRef): Unit =
-    if (settings.log containsPhase globalPhase)
-      inform("[log " + phase + "] " + msg)
+    if (shouldLogAtThisPhase)
+      inform("[log %s%s] %s".format(globalPhase, atPhaseStackMessage, msg))
 
   def logThrowable(t: Throwable): Unit = globalError(throwableAsString(t))
   def throwableAsString(t: Throwable): String =
@@ -754,6 +767,51 @@ class Global(var currentSettings: Settings, var reporter: Reporter) extends Symb
     line1 :: line2 :: descs mkString
   }
 
+  /** Returns List of (phase, value) pairs, including only those
+   *  where the value compares unequal to the previous phase's value.
+   */
+  def afterEachPhase[T](op: => T): List[(Phase, T)] = {
+    phaseDescriptors.map(_.ownPhase).foldLeft(List[(Phase, T)]()) { (res, ph) =>
+      val value = afterPhase(ph)(op)
+      if (res.nonEmpty && res.head._2 == value) res
+      else ((ph, value)) :: res
+    } reverse
+  }
+
+  /** Returns List of ChangeAfterPhase objects, encapsulating those
+   *  phase transitions where the result of the operation gave a different
+   *  list than it had when run during the previous phase.
+   */
+  def changesAfterEachPhase[T](op: => List[T]): List[ChangeAfterPhase[T]] = {
+    val ops = ((NoPhase, Nil)) :: afterEachPhase(op)
+
+    ops sliding 2 map {
+      case (_, before) :: (ph, after) :: Nil =>
+        val lost   = before filterNot (after contains _)
+        val gained = after filterNot (before contains _)
+        ChangeAfterPhase(ph, lost, gained)
+      case _ => ???
+    } toList
+  }
+  private def numberedPhase(ph: Phase) = "%2d/%s".format(ph.id, ph.name)
+
+  case class ChangeAfterPhase[+T](ph: Phase, lost: List[T], gained: List[T]) {
+    private def mkStr(what: String, xs: List[_]) = (
+      if (xs.isEmpty) ""
+      else xs.mkString(what + " after " + numberedPhase(ph) + " {\n  ", "\n  ", "\n}\n")
+    )
+    override def toString = mkStr("Lost", lost) + mkStr("Gained", gained)
+  }
+
+  def describeAfterEachPhase[T](op: => T): List[String] =
+    afterEachPhase(op) map { case (ph, t) => "[after %-15s] %s".format(numberedPhase(ph), t) }
+
+  def describeAfterEveryPhase[T](op: => T): String =
+    describeAfterEachPhase(op) map ("  " + _ + "\n") mkString
+
+  def printAfterEachPhase[T](op: => T): Unit =
+    describeAfterEachPhase(op) foreach (m => println("  " + m))
+
   // ----------- Runs ---------------------------------------
 
   private var curRun: Run = null
@@ -1027,9 +1085,11 @@ class Global(var currentSettings: Settings, var reporter: Reporter) extends Symb
     val refchecksPhase     = phaseNamed("refchecks")
     val uncurryPhase       = phaseNamed("uncurry")
     // tailcalls, specialize
+    val specializePhase    = phaseNamed("specialize")
     val explicitouterPhase = phaseNamed("explicitouter")
     val erasurePhase       = phaseNamed("erasure")
     // lazyvals, lambdalift, constructors
+    val lambdaLiftPhase    = phaseNamed("lambdalift")
     val flattenPhase       = phaseNamed("flatten")
     val mixinPhase         = phaseNamed("mixin")
     val cleanupPhase       = phaseNamed("cleanup")