[SPARK-52065][SQL] Produce another plan tree with output columns (name, data type, nullability) in plan change logging #50852

HeartSaVioR · 2025-05-10T09:49:01Z

What changes were proposed in this pull request?

We propose to add another tree string which focuses to produce output columns with data type and nullability. This will be shown in plan change logger, along with existing tree string plan.

For example, here is a one of example from plan change logging:

=== Applying Rule org.apache.spark.sql.execution.adaptive.InsertAdaptiveSparkPlan ===
!HashAggregate(keys=[id#334L], functions=[count(1)], output=[id#334L, count#335L])              AdaptiveSparkPlan isFinalPlan=false
!+- HashAggregate(keys=[id#334L], functions=[partial_count(1)], output=[id#334L, count#339L])   +- HashAggregate(keys=[id#334L], functions=[count(1)], output=[id#334L, count#335L])
!   +- Range (0, 1, step=1, splits=2)                                                              +- HashAggregate(keys=[id#334L], functions=[partial_count(1)], output=[id#334L, count#339L])
!                                                                                                     +- Range (0, 1, step=1, splits=2)

Output Information:
!HashAggregate <output=id#334L[nullable=false], count#335L[nullable=false]>      AdaptiveSparkPlan <output=id#334L[nullable=false], count#335L[nullable=false]>
!+- HashAggregate <output=id#334L[nullable=false], count#339L[nullable=false]>   +- HashAggregate <output=id#334L[nullable=false], count#335L[nullable=false]>
!   +- Range <output=id#334L[nullable=false]>                                       +- HashAggregate <output=id#334L[nullable=false], count#339L[nullable=false]>
!                                                                                      +- Range <output=id#334L[nullable=false]>

In some cases, it's not even feasible to evaluate the output of the node. (e.g. Project with Star expression) In that case, we will simply put <output=unresolved> since it's mostly due to UnresolvedException.

For example,

=== Applying Rule org.apache.spark.sql.catalyst.analysis.Analyzer$ResolveFunctions ===
!'Aggregate [id#334L], [id#334L, 'count(1) AS count#335]   Aggregate [id#334L], [id#334L, count(1) AS count#335L]
 +- Range (0, 1, step=1, splits=Some(2))                   +- Range (0, 1, step=1, splits=Some(2))

Output Information:
!Aggregate <output='Unresolved'>             Aggregate <output=id#334L[nullable=false], count#335L[nullable=false]>
 +- Range <output=id#334L[nullable=false]>   +- Range <output=id#334L[nullable=false]>

Why are the changes needed?

We recently got into very tricky issue (nullability change broke stateful operator) which required custom debug logging on plan change logging. This is because of lack of visibility for the output columns, especially their nullability, in our tree string of the plan.

Ideally, we shouldn't have two different tree strings and just make a fix to the existing tree string, but in many cases, current tree string is long enough so that we had to restrict the number of fields to show, hence we think it's better to have a separate tree plan for it.

Does this PR introduce any user-facing change?

Yes, when they change SQL config for plan change logger log level to their visible log level in log4j2 config. The application of this change is at least opt-in instead of opt-out.
(If we are changing the existing tree string, it will change many places.)

How was this patch tested?

Modified UT to cover the change.

Was this patch authored or co-authored using generative AI tooling?

No.

…nullability

HeartSaVioR · 2025-05-10T09:49:42Z

cc. @cloud-fan PTAL, thanks!

HeartSaVioR · 2025-05-14T04:50:07Z

@cloud-fan Friendly reminder - I know you are busy with release, so just in case if you have time.

HeartSaVioR · 2025-05-21T08:59:02Z

cc. @cloud-fan Friendly reminder to see your availability.

cloud-fan · 2025-05-21T09:51:45Z

sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/rules/RuleExecutor.scala

@@ -62,6 +62,9 @@ class PlanChangeLogger[TreeType <: TreeNode[_]] extends Logging {
          log"""
             |=== Applying Rule ${MDC(RULE_NAME, ruleName)} ===
             |${MDC(QUERY_PLAN, sideBySide(oldPlan.treeString, newPlan.treeString).mkString("\n"))}
+             |
+             |Output Information:
+             |${MDC(QUERY_PLAN, newPlan.treeStringWithOutputColumns)}


treeString is also a public method, can we just call it with printOutputColumns = true?

instead of a new section with new plan only, shall we change sideBySide(oldPlan.treeString, newPlan.treeString) to use the new string with output?

I think it's too long, verbose is not an optional param, so we need to specify both verbose and printOutputColumns. I'm OK if the length does not matter. Let me change it and revert if you see it be too long.

I'll make a change to do sideBySide here. Great suggestion!

cloud-fan · 2025-05-21T09:53:51Z

sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/trees/TreeNode.scala

@@ -1011,6 +1017,10 @@ abstract class TreeNode[BaseType <: TreeNode[BaseType]]
   */
  def innerChildren: Seq[TreeNode[_]] = Seq.empty

+  def nodeWithOutputColumnsString(maxColumns: Int): String = {
+    throw new UnsupportedOperationException("TreeNode does not have output columns")


to be conservative shall we just call simpleString here?

HeartSaVioR · 2025-05-21T13:50:10Z

Thanks @cloud-fan for your review! I've addressed your comments. Please take another look when you have time. Thanks!

cloud-fan · 2025-05-22T14:46:36Z

sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/rules/RuleExecutor.scala

          log"""
             |=== Applying Rule ${MDC(RULE_NAME, ruleName)} ===
             |${MDC(QUERY_PLAN, sideBySide(oldPlan.treeString, newPlan.treeString).mkString("\n"))}
+             |
+             |Output Information:
+             |${MDC(QUERY_PLAN, sideBySide(oldPlan.treeString(verbose = false, printOutputColumns = true), newPlan.treeString(verbose = false, printOutputColumns = true)))}


nit:

val oldPlanStringWithOutput = ... val newPlanStringWithOutput log""" ... ... sideBySide(oldPlanStringWithOutput, newPlanStringWithOutput)

Can we update the PR description to reflect this change?

Good point. Didn't realize the message() method itself is lazily evaluated.

Also updated the PR description.

HeartSaVioR · 2025-05-25T22:53:13Z

@cloud-fan I've addressed your feedback. PTAL, thanks!

cloud-fan · 2025-05-29T14:22:27Z

sql/catalyst/src/main/scala/org/apache/spark/sql/catalyst/rules/RuleExecutor.scala

+            printOutputColumns = true)
+          val newPlanStringWithOutput = newPlan.treeString(verbose = false,
+            printOutputColumns = true)
+          // scalastyle:off line.size.limit
          log"""
             |=== Result of Batch ${MDC(BATCH_NAME, batchName)} ===
             |${MDC(QUERY_PLAN, sideBySide(oldPlan.treeString, newPlan.treeString).mkString("\n"))}


What if we append the output info in the verbose treeString? Is the diff readable?

HeartSaVioR added 4 commits May 9, 2025 13:06

[WIP] Change the plan change log to also produce output columns with …

365598c

…nullability

Compilation is fixed

e243f9d

fix AQE test failure

7a61566

modified test to cover the change

94c62c4

github-actions bot added the SQL label May 10, 2025

cloud-fan reviewed May 21, 2025

View reviewed changes

first pass reviews

fee4a2b

cloud-fan reviewed May 22, 2025

View reviewed changes

feedback

63dbb95

HeartSaVioR requested a review from cloud-fan May 29, 2025 12:54

cloud-fan reviewed May 29, 2025

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

[SPARK-52065][SQL] Produce another plan tree with output columns (name, data type, nullability) in plan change logging #50852

[SPARK-52065][SQL] Produce another plan tree with output columns (name, data type, nullability) in plan change logging #50852

Uh oh!

HeartSaVioR commented May 10, 2025 •

edited

Loading

Uh oh!

HeartSaVioR commented May 10, 2025

Uh oh!

HeartSaVioR commented May 14, 2025

Uh oh!

HeartSaVioR commented May 21, 2025

Uh oh!

cloud-fan May 21, 2025

Uh oh!

cloud-fan May 21, 2025

Uh oh!

HeartSaVioR May 21, 2025

Uh oh!

cloud-fan May 21, 2025

Uh oh!

HeartSaVioR commented May 21, 2025

Uh oh!

cloud-fan May 22, 2025

Uh oh!

cloud-fan May 22, 2025

Uh oh!

HeartSaVioR May 23, 2025

Uh oh!

HeartSaVioR May 23, 2025

Uh oh!

HeartSaVioR commented May 25, 2025

Uh oh!

cloud-fan May 29, 2025

Uh oh!

Uh oh!

[SPARK-52065][SQL] Produce another plan tree with output columns (name, data type, nullability) in plan change logging #50852

Are you sure you want to change the base?

[SPARK-52065][SQL] Produce another plan tree with output columns (name, data type, nullability) in plan change logging #50852

Uh oh!

Conversation

HeartSaVioR commented May 10, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What changes were proposed in this pull request?

Why are the changes needed?

Does this PR introduce any user-facing change?

How was this patch tested?

Was this patch authored or co-authored using generative AI tooling?

Uh oh!

HeartSaVioR commented May 10, 2025

Uh oh!

HeartSaVioR commented May 14, 2025

Uh oh!

HeartSaVioR commented May 21, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

HeartSaVioR commented May 21, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

HeartSaVioR commented May 25, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

HeartSaVioR commented May 10, 2025 •

edited

Loading