forked from apache/spark
-
Notifications
You must be signed in to change notification settings - Fork 0
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
[SPARK-25415][SQL] Make plan change log in RuleExecutor configurable …
…by SQLConf ## What changes were proposed in this pull request? In RuleExecutor, after applying a rule, if the plan has changed, the before and after plan will be logged using level "trace". At times, however, such information can be very helpful for debugging. Hence, making the log level configurable in SQLConf would allow users to turn on the plan change log independently and save the trouble of tweaking log4j settings. Meanwhile, filtering plan change log for specific rules can also be very useful. So this PR adds two SQL configurations: 1. spark.sql.optimizer.planChangeLog.level - set a specific log level for logging plan changes after a rule is applied. 2. spark.sql.optimizer.planChangeLog.rules - enable plan change logging only for a set of specified rules, separated by commas. ## How was this patch tested? Added UT. Closes apache#22406 from maryannxue/spark-25415. Authored-by: maryannxue <[email protected]> Signed-off-by: gatorsmile <[email protected]>
- Loading branch information
1 parent
3af2bb8
commit e5899d4
Showing
3 changed files
with
200 additions
and
5 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
148 changes: 148 additions & 0 deletions
148
...talyst/src/test/scala/org/apache/spark/sql/catalyst/optimizer/OptimizerLoggingSuite.scala
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,148 @@ | ||
| /* | ||
| * Licensed to the Apache Software Foundation (ASF) under one or more | ||
| * contributor license agreements. See the NOTICE file distributed with | ||
| * this work for additional information regarding copyright ownership. | ||
| * The ASF licenses this file to You under the Apache License, Version 2.0 | ||
| * (the "License"); you may not use this file except in compliance with | ||
| * the License. You may obtain a copy of the License at | ||
| * | ||
| * http://www.apache.org/licenses/LICENSE-2.0 | ||
| * | ||
| * Unless required by applicable law or agreed to in writing, software | ||
| * distributed under the License is distributed on an "AS IS" BASIS, | ||
| * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
| * See the License for the specific language governing permissions and | ||
| * limitations under the License. | ||
| */ | ||
|
|
||
| package org.apache.spark.sql.catalyst.optimizer | ||
|
|
||
| import scala.collection.mutable.ArrayBuffer | ||
|
|
||
| import org.apache.log4j.{Appender, AppenderSkeleton, Level, Logger} | ||
| import org.apache.log4j.spi.LoggingEvent | ||
|
|
||
| import org.apache.spark.sql.catalyst.dsl.expressions._ | ||
| import org.apache.spark.sql.catalyst.dsl.plans._ | ||
| import org.apache.spark.sql.catalyst.plans.PlanTest | ||
| import org.apache.spark.sql.catalyst.plans.logical.{LocalRelation, LogicalPlan} | ||
| import org.apache.spark.sql.catalyst.rules.RuleExecutor | ||
| import org.apache.spark.sql.internal.SQLConf | ||
|
|
||
| class OptimizerLoggingSuite extends PlanTest { | ||
|
|
||
| object Optimize extends RuleExecutor[LogicalPlan] { | ||
| val batches = Batch("Optimizer Batch", FixedPoint(100), | ||
| PushDownPredicate, | ||
| ColumnPruning, | ||
| CollapseProject) :: Nil | ||
| } | ||
|
|
||
| class MockAppender extends AppenderSkeleton { | ||
| val loggingEvents = new ArrayBuffer[LoggingEvent]() | ||
|
|
||
| override def append(loggingEvent: LoggingEvent): Unit = { | ||
| if (loggingEvent.getRenderedMessage().contains("Applying Rule")) { | ||
| loggingEvents.append(loggingEvent) | ||
| } | ||
| } | ||
|
|
||
| override def close(): Unit = {} | ||
| override def requiresLayout(): Boolean = false | ||
| } | ||
|
|
||
| private def withLogLevelAndAppender(level: Level, appender: Appender)(f: => Unit): Unit = { | ||
| val logger = Logger.getLogger(Optimize.getClass.getName.dropRight(1)) | ||
| val restoreLevel = logger.getLevel | ||
| logger.setLevel(level) | ||
| logger.addAppender(appender) | ||
| try f finally { | ||
| logger.setLevel(restoreLevel) | ||
| logger.removeAppender(appender) | ||
| } | ||
| } | ||
|
|
||
| private def verifyLog(expectedLevel: Level, expectedRules: Seq[String]): Unit = { | ||
| val logAppender = new MockAppender() | ||
| withLogLevelAndAppender(Level.TRACE, logAppender) { | ||
| val input = LocalRelation('a.int, 'b.string, 'c.double) | ||
| val query = input.select('a, 'b).select('a).where('a > 1).analyze | ||
| val expected = input.where('a > 1).select('a).analyze | ||
| comparePlans(Optimize.execute(query), expected) | ||
| } | ||
| val logMessages = logAppender.loggingEvents.map(_.getRenderedMessage) | ||
| assert(expectedRules.forall(rule => logMessages.exists(_.contains(rule)))) | ||
| assert(logAppender.loggingEvents.forall(_.getLevel == expectedLevel)) | ||
| } | ||
|
|
||
| test("test log level") { | ||
| val levels = Seq( | ||
| "TRACE" -> Level.TRACE, | ||
| "trace" -> Level.TRACE, | ||
| "DEBUG" -> Level.DEBUG, | ||
| "debug" -> Level.DEBUG, | ||
| "INFO" -> Level.INFO, | ||
| "info" -> Level.INFO, | ||
| "WARN" -> Level.WARN, | ||
| "warn" -> Level.WARN, | ||
| "ERROR" -> Level.ERROR, | ||
| "error" -> Level.ERROR, | ||
| "deBUG" -> Level.DEBUG) | ||
|
|
||
| levels.foreach { level => | ||
| withSQLConf(SQLConf.OPTIMIZER_PLAN_CHANGE_LOG_LEVEL.key -> level._1) { | ||
| verifyLog( | ||
| level._2, | ||
| Seq( | ||
| PushDownPredicate.ruleName, | ||
| ColumnPruning.ruleName, | ||
| CollapseProject.ruleName)) | ||
| } | ||
| } | ||
| } | ||
|
|
||
| test("test invalid log level conf") { | ||
| val levels = Seq( | ||
| "", | ||
| "*d_", | ||
| "infoo") | ||
|
|
||
| levels.foreach { level => | ||
| val error = intercept[IllegalArgumentException] { | ||
| withSQLConf(SQLConf.OPTIMIZER_PLAN_CHANGE_LOG_LEVEL.key -> level) {} | ||
| } | ||
| assert(error.getMessage.contains( | ||
| "Invalid value for 'spark.sql.optimizer.planChangeLog.level'.")) | ||
| } | ||
| } | ||
|
|
||
| test("test log rules") { | ||
| val rulesSeq = Seq( | ||
| Seq(PushDownPredicate.ruleName, | ||
| ColumnPruning.ruleName, | ||
| CollapseProject.ruleName).reduce(_ + "," + _) -> | ||
| Seq(PushDownPredicate.ruleName, | ||
| ColumnPruning.ruleName, | ||
| CollapseProject.ruleName), | ||
| Seq(PushDownPredicate.ruleName, | ||
| ColumnPruning.ruleName).reduce(_ + "," + _) -> | ||
| Seq(PushDownPredicate.ruleName, | ||
| ColumnPruning.ruleName), | ||
| CollapseProject.ruleName -> | ||
| Seq(CollapseProject.ruleName), | ||
| Seq(ColumnPruning.ruleName, | ||
| "DummyRule").reduce(_ + "," + _) -> | ||
| Seq(ColumnPruning.ruleName), | ||
| "DummyRule" -> Seq(), | ||
| "" -> Seq() | ||
| ) | ||
|
|
||
| rulesSeq.foreach { case (rulesConf, expectedRules) => | ||
| withSQLConf( | ||
| SQLConf.OPTIMIZER_PLAN_CHANGE_LOG_RULES.key -> rulesConf, | ||
| SQLConf.OPTIMIZER_PLAN_CHANGE_LOG_LEVEL.key -> "INFO") { | ||
| verifyLog(Level.INFO, expectedRules) | ||
| } | ||
| } | ||
| } | ||
| } |