You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hive.apache.org by za...@apache.org on 2021/12/22 14:47:35 UTC
[hive] branch master updated: HIVE-25816: Log CBO plan after rule application for debugging purposes (Stamatis Zampetakis, reviewed by Krisztian Kasa)
This is an automated email from the ASF dual-hosted git repository.
zabetak pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/hive.git
The following commit(s) were added to refs/heads/master by this push:
new 9087fa9 HIVE-25816: Log CBO plan after rule application for debugging purposes (Stamatis Zampetakis, reviewed by Krisztian Kasa)
9087fa9 is described below
commit 9087fa93cd785223f4f2552ec836e7580c78830a
Author: Stamatis Zampetakis <za...@gmail.com>
AuthorDate: Thu Dec 16 16:27:56 2021 +0100
HIVE-25816: Log CBO plan after rule application for debugging purposes (Stamatis Zampetakis, reviewed by Krisztian Kasa)
Closes #2887
---
data/conf/hive-log4j2.properties | 11 ++-
.../hadoop/hive/ql/optimizer/calcite/Bug.java | 5 ++
.../hive/ql/optimizer/calcite/RuleEventLogger.java | 82 ++++++++++++++++++++++
.../hadoop/hive/ql/parse/CalcitePlanner.java | 7 +-
4 files changed, 102 insertions(+), 3 deletions(-)
diff --git a/data/conf/hive-log4j2.properties b/data/conf/hive-log4j2.properties
index 3072efd..eac59b3 100644
--- a/data/conf/hive-log4j2.properties
+++ b/data/conf/hive-log4j2.properties
@@ -50,7 +50,7 @@ appender.DRFA.strategy.type = DefaultRolloverStrategy
appender.DRFA.strategy.max = 30
# list of all loggers
-loggers = HadoopIPC, HadoopSecurity, Hdfs, HdfsServer, HadoopMetrics2, Mortbay, Yarn, YarnServer, Tez, HadoopConf, Zookeeper, ServerCnxn, NIOServerCnxn, ClientCnxn, ClientCnxnSocket, ClientCnxnSocketNIO, DataNucleus, Datastore, JPOX, Operator, Serde2Lazy, ObjectStore, CalcitePlanner, AmazonAws, ApacheHttp, Thrift, Jetty, BlockStateChange, swo
+loggers = HadoopIPC, HadoopSecurity, Hdfs, HdfsServer, HadoopMetrics2, Mortbay, Yarn, YarnServer, Tez, HadoopConf, Zookeeper, ServerCnxn, NIOServerCnxn, ClientCnxn, ClientCnxnSocket, ClientCnxnSocketNIO, DataNucleus, Datastore, JPOX, Operator, Serde2Lazy, ObjectStore, CalcitePlanner, AmazonAws, ApacheHttp, Thrift, Jetty, BlockStateChange, swo, CBORuleLogger
logger.HadoopIPC.name = org.apache.hadoop.ipc
logger.HadoopIPC.level = WARN
@@ -121,6 +121,15 @@ logger.ObjectStore.level = INFO
logger.CalcitePlanner.name = org.apache.calcite.plan.RelOptPlanner
logger.CalcitePlanner.level = INFO
+# Change logger level to DEBUG, to see all application of CBO rules and the operators they produce
+logger.CBORuleLogger.name = org.apache.hadoop.hive.ql.optimizer.calcite.RuleEventLogger
+logger.CBORuleLogger.level = OFF
+logger.CBORuleLogger.filter.marker.type = MarkerFilter
+logger.CBORuleLogger.filter.marker.marker = FULL_PLAN
+# Change filter to ACCEPT, to see the produced plan after every rule invocation using the EXPLAIN CBO format
+logger.CBORuleLogger.filter.marker.onMatch = DENY
+logger.CBORuleLogger.filter.marker.onMisMatch = NEUTRAL
+
logger.AmazonAws.name=com.amazonaws
logger.AmazonAws.level = INFO
diff --git a/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/Bug.java b/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/Bug.java
index ce0636d..a05fb80 100644
--- a/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/Bug.java
+++ b/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/Bug.java
@@ -69,4 +69,9 @@ public final class Bug {
* Whether <a href="https://issues.apache.org/jira/browse/CALCITE-4574">CALCITE-4574</a> is fixed.
*/
public static final boolean CALCITE_4574_FIXED = false;
+
+ /**
+ * Whether <a href="https://issues.apache.org/jira/browse/CALCITE-4704">CALCITE-4704</a> is fixed.
+ */
+ public static final boolean CALCITE_4704_FIXED = false;
}
diff --git a/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/RuleEventLogger.java b/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/RuleEventLogger.java
new file mode 100644
index 0000000..f5ab294
--- /dev/null
+++ b/ql/src/java/org/apache/hadoop/hive/ql/optimizer/calcite/RuleEventLogger.java
@@ -0,0 +1,82 @@
+/*
+ * 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.hadoop.hive.ql.optimizer.calcite;
+
+import org.apache.calcite.plan.RelOptListener;
+import org.apache.calcite.plan.RelOptRuleCall;
+import org.apache.calcite.plan.RelOptUtil;
+import org.apache.calcite.rel.RelNode;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
+import java.util.Arrays;
+import java.util.stream.Collectors;
+
+/**
+ * Listener for logging useful debugging information on certain rule events.
+ */
+public class RuleEventLogger implements RelOptListener {
+ private static final Logger LOG = LoggerFactory.getLogger(RuleEventLogger.class.getName());
+ private static final Marker FULL = MarkerFactory.getMarker("FULL_PLAN");
+
+ public RuleEventLogger() {
+ if (Bug.CALCITE_4704_FIXED) {
+ throw new IllegalStateException("Class redundant after fix is merged into Calcite");
+ }
+ }
+
+ @Override
+ public void relEquivalenceFound(final RelEquivalenceEvent event) {
+
+ }
+
+ @Override
+ public void ruleAttempted(final RuleAttemptedEvent event) {
+ if (event.isBefore() && LOG.isDebugEnabled()) {
+ RelOptRuleCall call = event.getRuleCall();
+ String ruleArgs = Arrays.stream(call.rels).map(rel -> "rel#" + rel.getId() + ":" + rel.getRelTypeName())
+ .collect(Collectors.joining(","));
+ LOG.debug("call#{}: Apply rule [{}] to [{}]", call.id, call.getRule(), ruleArgs);
+ }
+ }
+
+ @Override
+ public void ruleProductionSucceeded(RuleProductionEvent event) {
+ if (event.isBefore() && LOG.isDebugEnabled()) {
+ RelOptRuleCall call = event.getRuleCall();
+ RelNode newRel = event.getRel();
+ String description = newRel == null ? "null" : "rel#" + newRel.getId() + ":" + newRel.getRelTypeName();
+ LOG.debug("call#{}: Rule [{}] produced [{}]", call.id, call.getRule(), description);
+ if (newRel != null) {
+ LOG.debug(FULL, "call#{}: Full plan for [{}]:{}", call.id, description,
+ System.lineSeparator() + RelOptUtil.toString(newRel));
+ }
+ }
+ }
+
+ @Override
+ public void relDiscarded(final RelDiscardedEvent event) {
+
+ }
+
+ @Override
+ public void relChosen(final RelChosenEvent event) {
+
+ }
+}
diff --git a/ql/src/java/org/apache/hadoop/hive/ql/parse/CalcitePlanner.java b/ql/src/java/org/apache/hadoop/hive/ql/parse/CalcitePlanner.java
index 12dcebd..1b7af3e 100644
--- a/ql/src/java/org/apache/hadoop/hive/ql/parse/CalcitePlanner.java
+++ b/ql/src/java/org/apache/hadoop/hive/ql/parse/CalcitePlanner.java
@@ -164,6 +164,7 @@ import org.apache.hadoop.hive.ql.optimizer.calcite.HiveCalciteUtil;
import org.apache.hadoop.hive.ql.optimizer.calcite.HiveConfPlannerContext;
import org.apache.hadoop.hive.ql.optimizer.calcite.HiveDefaultRelMetadataProvider;
import org.apache.hadoop.hive.ql.optimizer.calcite.HiveTezModelRelMetadataProvider;
+import org.apache.hadoop.hive.ql.optimizer.calcite.RuleEventLogger;
import org.apache.hadoop.hive.ql.optimizer.calcite.rules.HiveAggregateSortLimitRule;
import org.apache.hadoop.hive.ql.optimizer.calcite.rules.HiveJoinSwapConstraintsRule;
import org.apache.hadoop.hive.ql.optimizer.calcite.rules.HiveSemiJoinProjectTransposeRule;
@@ -519,7 +520,9 @@ public class CalcitePlanner extends SemanticAnalyzer {
corrScalarRexSQWithAgg,
new HiveConfPlannerContext(isCorrelatedColumns, heuristicMaterializationStrategy, isExplainPlan),
statsSource);
- return HiveVolcanoPlanner.createPlanner(confContext);
+ RelOptPlanner planner = HiveVolcanoPlanner.createPlanner(confContext);
+ planner.addListener(new RuleEventLogger());
+ return planner;
}
@Override
@@ -2413,7 +2416,7 @@ public class CalcitePlanner extends SemanticAnalyzer {
// Create planner and copy context
HepPlanner planner = new HepPlanner(program,
basePlan.getCluster().getPlanner().getContext());
-
+ planner.addListener(new RuleEventLogger());
List<RelMetadataProvider> list = Lists.newArrayList();
list.add(mdProvider);
planner.registerMetadataProviders(list);