Log before/after plans when an optimizer rule fires

iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/planner/plan/node/PlanGraphJsonPrinter.java

@@ -74,7 +74,13 @@ private static JsonObject buildJsonNode(PlanNode node) {
       jsonNode.add("properties", properties);
     }
 
-    List<PlanNode> children = node.getChildren();
+    List<PlanNode> children;
+    try {
+      children = node.getChildren();
+    } catch (UnsupportedOperationException e) {
+      // GroupReference, which appears inside the iterative optimizer's memo, has no children.
+      children = null;
+    }
     if (children != null && !children.isEmpty()) {
       JsonArray childrenArray = new JsonArray();
       for (PlanNode child : children) {

iotdb-core/datanode/src/main/java/org/apache/iotdb/db/queryengine/plan/relational/planner/iterative/IterativeOptimizer.java

@@ -29,6 +29,7 @@
 import org.apache.iotdb.db.i18n.DataNodeQueryMessages;
 import org.apache.iotdb.db.queryengine.common.QueryId;
 import org.apache.iotdb.db.queryengine.execution.warnings.WarningCollector;
+import org.apache.iotdb.db.queryengine.plan.planner.plan.node.PlanGraphJsonPrinter;
 import org.apache.iotdb.db.queryengine.plan.relational.execution.querystats.PlanOptimizersStatsCollector;
 import org.apache.iotdb.db.queryengine.plan.relational.execution.querystats.QueryPlanOptimizerStatistics;
 import org.apache.iotdb.db.queryengine.plan.relational.planner.PlannerContext;
@@ -210,17 +211,19 @@ private <T> Rule.Result transform(PlanNode node, Rule<T> rule, Context context)
       try {
         long start = nanoTime();
         result = rule.apply(match.capture(nodeCapture), match.captures(), ruleContext(context));
-
-        if (LOG.isDebugEnabled() && !result.isEmpty()) {
-          LOG.debug(
-              DataNodeQueryMessages.RULE_S_BEFORE_S_AFTER_S, rule.getClass().getName(), "", "");
-        }
         duration = nanoTime() - start;
       } catch (RuntimeException e) {
         stats.recordFailure(rule);
         context.iterativeOptimizerStatsCollector.recordFailure(rule);
         throw e;
       }
+      if (LOG.isDebugEnabled() && !result.isEmpty()) {
+        LOG.debug(
+            DataNodeQueryMessages.RULE_S_BEFORE_S_AFTER_S,
+            rule.getClass().getName(),
+            renderPlan(node),
+            renderPlan(result.getTransformedPlan().get()));
+      }
       stats.record(rule, duration, !result.isEmpty());
 
       if (result.getTransformedPlan().isPresent()) {
@@ -231,6 +234,19 @@ private <T> Rule.Result transform(PlanNode node, Rule<T> rule, Context context)
     return Rule.Result.empty();
   }
 
+  /**
+   * Renders the subtree rooted at the given node for the rule-application debug log. Rendering is
+   * best-effort: it runs on optimizer-internal nodes, so a rendering failure must not fail the
+   * query and falls back to the node's own {@code toString}.
+   */
+  private static String renderPlan(PlanNode node) {
+    try {
+      return String.join(System.lineSeparator(), PlanGraphJsonPrinter.getJsonLines(node));
+    } catch (RuntimeException e) {
+      return node.toString();
+    }
+  }
+
   private boolean exploreChildren(int group, Context context, Set<PlanNodeId> changedPlanNodeIds) {
     boolean progress = false;
 

iotdb-core/datanode/src/test/java/org/apache/iotdb/db/queryengine/plan/planner/node/PlanGraphJsonPrinterTest.java

@@ -34,6 +34,7 @@
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.OrderingScheme;
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.SortOrder;
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.Symbol;
+import org.apache.iotdb.commons.queryengine.plan.relational.planner.iterative.GroupReference;
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.node.AggregationNode;
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.node.FilterNode;
 import org.apache.iotdb.commons.queryengine.plan.relational.planner.node.JoinNode;
@@ -570,4 +571,22 @@ public void testAggregationNodeProperties() {
     assertEquals("device", props.getAsJsonArray("PreGroupedSymbols").get(0).getAsString());
     assertEquals("SINGLE", props.get("Step").getAsString());
   }
+
+  @Test
+  public void testGroupReferenceIsRenderedAsLeaf() {
+    // GroupReference appears as a child inside the iterative optimizer's memo and throws from
+    // getChildren(); the printer must still render such a plan without failing.
+    GroupReference groupReference =
+        new GroupReference(new PlanNodeId("groupRef"), 1, ImmutableList.of(new Symbol("s1")));
+    LimitNode limitNode =
+        new LimitNode(new PlanNodeId("limit"), groupReference, 10, Optional.empty());
+
+    JsonObject root =
+        JsonParser.parseString(PlanGraphJsonPrinter.toPrettyJson(limitNode)).getAsJsonObject();
+    JsonObject child = root.getAsJsonArray("children").get(0).getAsJsonObject();
+
+    assertEquals("LimitNode-limit", root.get("name").getAsString());
+    assertEquals("GroupReference-groupRef", child.get("name").getAsString());
+    assertFalse(child.has("children"));
+  }
 }