[SQL] Better logging when applying rules.

Author: Michael Armbrust <[email protected]> Closes #616 from marmbrus/ruleLogging and squashes the following commits: 39c09fe [Michael Armbrust] Fix off by one error. 5af3537 [Michael Armbrust] Better logging when applying rules. (cherry picked from commit b295714) Signed-off-by: Reynold Xin <[email protected]>
apache · May 4, 2014 · e24d5cd · e24d5cd
1 parent 8406ac4
commit e24d5cd
Showing 1 changed file with 24 additions and 4 deletions.
diff --git a/sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/rules/RuleExecutor.scala b/sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/rules/RuleExecutor.scala
@@ -50,18 +50,18 @@ abstract class RuleExecutor[TreeType <: TreeNode[_]] extends Logging {
     var curPlan = plan
 
     batches.foreach { batch =>
+      val batchStartPlan = curPlan
       var iteration = 1
       var lastPlan = curPlan
-      curPlan = batch.rules.foldLeft(curPlan) { case (plan, rule) => rule(plan) }
+      var continue = true
 
       // Run until fix point (or the max number of iterations as specified in the strategy.
-      while (iteration < batch.strategy.maxIterations && !curPlan.fastEquals(lastPlan)) {
-        lastPlan = curPlan
+      while (continue) {
         curPlan = batch.rules.foldLeft(curPlan) {
           case (plan, rule) =>
             val result = rule(plan)
             if (!result.fastEquals(plan)) {
-              logger.debug(
+              logger.trace(
                 s"""
                   |=== Applying Rule ${rule.ruleName} ===
                   |${sideBySide(plan.treeString, result.treeString).mkString("\n")}
@@ -71,6 +71,26 @@ abstract class RuleExecutor[TreeType <: TreeNode[_]] extends Logging {
             result
         }
         iteration += 1
+        if (iteration > batch.strategy.maxIterations) {
+          logger.info(s"Max iterations ($iteration) reached for batch ${batch.name}")
+          continue = false
+        }
+
+        if (curPlan.fastEquals(lastPlan)) {
+          logger.trace(s"Fixed point reached for batch ${batch.name} after $iteration iterations.")
+          continue = false
+        }
+        lastPlan = curPlan
+      }
+
+      if (!batchStartPlan.fastEquals(curPlan)) {
+        logger.debug(
+          s"""
+          |=== Result of Batch ${batch.name} ===
+          |${sideBySide(plan.treeString, curPlan.treeString).mkString("\n")}
+        """.stripMargin)
+      } else {
+        logger.trace(s"Batch ${batch.name} has no effect.")
       }
     }