You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@calcite.apache.org by GitBox <gi...@apache.org> on 2020/04/11 03:05:22 UTC
[GitHub] [calcite] xndai opened a new pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
xndai opened a new pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910
…DEBUG log level
1. Fix current VolcanoPlanner's rule listener to use MulticastRelOptListener so multiple listeners can be added at the same time.
2. Create a RuleAttemptsListener that records attempts of each rule and the time of rule firing. The listener is only added when logger is at DEBUG level, or lower.
3. Move some verbose log from debug to trace level.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r410019981
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
Agree with @hsyuan
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407613128
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
+ entry.getKey(),
+ NumberFormat.getNumberInstance(Locale.US).format(entry.getValue().left),
+ NumberFormat.getNumberInstance(Locale.US).format(entry.getValue().right)));
Review comment:
Make sense. Fixed.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409389345
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
Review comment:
Can you please use Comparators.... then then then to make the output stable?
Currently, you use a single field only for the sort, so the ties will appear as randomly sorted rows :-/
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409156274
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
Getting RuleAttemptsListener out of MulticastRelOptListener would require a down casting and relay on the implementation detail that the RuleAttemptsListener is always the first listener, which is tricky. And the dump() method is specific to the RuleAttemptsListener, and I don't think it should become part of the interface.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407327831
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
Maybe reasonable, but it is another topic, should be resolved in another issue and it is better if there is a discussion about this switch.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407338270
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -64,19 +45,8 @@
import java.io.PrintWriter;
import java.io.StringWriter;
-import java.util.ArrayDeque;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Comparator;
-import java.util.Deque;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.IdentityHashMap;
-import java.util.Iterator;
-import java.util.LinkedHashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
+import java.text.NumberFormat;
+import java.util.*;
Review comment:
Fixed. We need to fix the style check as well. Such things should be enforced by tool.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409862343
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
Review comment:
I reserve some space so they are more readable. The Jira has an example output.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407310226
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,66 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
Review comment:
It's only referenced at two places. Not very necessary.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407330555
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
Why not just discuss here? Right now there are just too many logs at DEBUG level, including all the rule firing and transformations. I try to separate DEBUG and TRACE so we could get the important ones when enable DEBUG, things like the best plan, rules attempted, etc. Without the log level change, this PR is not quite useful.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r410499729
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
done
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407302718
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -64,19 +45,8 @@
import java.io.PrintWriter;
import java.io.StringWriter;
-import java.util.ArrayDeque;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Comparator;
-import java.util.Deque;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.IdentityHashMap;
-import java.util.Iterator;
-import java.util.LinkedHashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
+import java.text.NumberFormat;
+import java.util.*;
Review comment:
Please expand this to avoid style problems?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407309904
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
The reason is you would need to access it at the end to dump rule information.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407320340
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,66 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
Review comment:
Can we also add such a listener for HepPlanner?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409385740
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ NumberFormat usFormat = NumberFormat.getNumberInstance(Locale.US);
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
+ entry.getKey(),
+ usFormat.format(entry.getValue().left),
+ usFormat.getNumberInstance(Locale.US).format(entry.getValue().right)));
Review comment:
```suggestion
usFormat.format(entry.getValue().right)));
```
Is there a reason you did not move the second `getNumberInstance` out of the loop?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407045528
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,70 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list, new Comparator<Map.Entry<String, Pair<Long, Long>>>() {
Review comment:
Would it be better to simply like below?
```
Collections.sort(list, (left, right) -> right.getValue().left.compareTo(left.getValue().left));
```
or
```
Collections.sort(list, Map.Entry.<String, Pair<Long, Long>>comparingByValue(
Comparator.comparingLong(Pair::getKey)).reversed());
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409862498
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ NumberFormat usFormat = NumberFormat.getNumberInstance(Locale.US);
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
+ entry.getKey(),
+ usFormat.format(entry.getValue().left),
+ usFormat.getNumberInstance(Locale.US).format(entry.getValue().right)));
Review comment:
No, it was mistake. fixed.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407045528
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,70 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list, new Comparator<Map.Entry<String, Pair<Long, Long>>>() {
Review comment:
Would it be better to simply like below:
1)
```
Collections.sort(list, (left, right) -> right.getValue().left.compareTo(left.getValue().left));
```
or
2)
```
Collections.sort(list, Map.Entry.<String, Pair<Long, Long>>comparingByValue(
Comparator.comparingLong(Pair::getKey)).reversed());
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407327389
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
Seems not necessary, either we get the `RuleAttemptsListener ` out of the `MulticastRelOptListener` or we add a new interface `RelOptListener#dump` or `RelOptListener#close` .
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] hsyuan commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
hsyuan commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409862155
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
Better use `RuleAttemptsListener.class.getName()`?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407304411
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,66 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
Review comment:
Extract "60s%20s%20s%n" as a final format string?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407305137
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
It seems this field is never initialized?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409862785
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
Now I use a separate logger for RuleAttemptsInfo. Please check.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407307175
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
Is there a special reason we add this as a class member?
A planner may have a number of different listeners.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409385050
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
> Without the log level change, this PR is not quite useful.
@xndai , this is exactly why I suggest that we should use **categories** rather than `log levels` to configure planner tracing.
What you add looks more like a standalone debugging feature rather than a yet another logging level.
We should move heavyweight logging to their own categories otherwise we never converge on what is debug and what is trace.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
chunweilei commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407318309
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -64,19 +45,8 @@
import java.io.PrintWriter;
import java.io.StringWriter;
-import java.util.ArrayDeque;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Comparator;
-import java.util.Deque;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.IdentityHashMap;
-import java.util.Iterator;
-import java.util.LinkedHashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
+import java.text.NumberFormat;
+import java.util.*;
Review comment:
I think it's not expected considering the calcite code convention.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407326561
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
The DEBUG messages would be too verbose to be useful if we keep this at DEBUG.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r410184622
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
`RuleAttemptsListener` is private, so there's no way to use it here.
What if we use `AbstractRelOptPlanner.class.getName() + ".rule_execution_summary"` or something like that?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407097727
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,70 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list, new Comparator<Map.Entry<String, Pair<Long, Long>>>() {
Review comment:
Absolutely! Thanks.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407365547
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -96,6 +101,11 @@ protected AbstractRelOptPlanner(RelOptCostFactory costFactory,
// these types, but some operands may use them.
classes.add(RelNode.class);
classes.add(RelSubset.class);
+
+ if (LOGGER.isDebugEnabled()) {
+ this.ruleAttemptsListener = new RuleAttemptsListener();
Review comment:
Should it use its own logging category instead?
Then it can be a trace level for its own category.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r410498305
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
I don't want to break from the convention that we use full class name as logger name. There are already a couple of hard coded class names there. I personally don't think it's a problem.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409388114
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
Review comment:
I guess it would be easier to read if the numeric columns were the first ones.
Does the number of attempts really need 20 characters?
Does the duration take 20 characters?
Can you please provide sample output?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
liyafan82 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407305137
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -167,7 +137,13 @@
/**
* Listener for this planner, or null if none set.
*/
- RelOptListener listener;
+ MulticastRelOptListener listener;
+
+ /**
+ * Listener for couting the attempts of each rule.
+ * Only enabled under DEBUG.
+ */
+ RuleAttemptsListener ruleAttemptsListener;
Review comment:
It seems this field is never initialized?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407045528
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,70 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list, new Comparator<Map.Entry<String, Pair<Long, Long>>>() {
Review comment:
Would it be better to simply like below:
1) `Collections.sort(list, (left, right) -> right.getValue().left.compareTo(left.getValue().left));`
or
2)
```
Collections.sort(list, Map.Entry.<String, Pair<Long, Long>>comparingByValue(
Comparator.comparingLong(Pair::getKey)).reversed());
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407338385
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,66 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
Review comment:
Fixed.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
neoremind commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407045528
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -1757,4 +1738,70 @@ protected void onMatch() {
this.callId = callId;
}
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long totalAttempts;
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ this.totalAttempts = 0;
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ ++this.totalAttempts;
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list, new Comparator<Map.Entry<String, Pair<Long, Long>>>() {
Review comment:
Would it be better to simplify like below?
```
Collections.sort(list, (left, right) -> right.getValue().left.compareTo(left.getValue().left));
```
or
```
Collections.sort(list, Map.Entry.<String, Pair<Long, Long>>comparingByValue(
Comparator.comparingLong(Pair::getKey)).reversed());
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407309807
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -64,19 +45,8 @@
import java.io.PrintWriter;
import java.io.StringWriter;
-import java.util.ArrayDeque;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Comparator;
-import java.util.Deque;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.IdentityHashMap;
-import java.util.Iterator;
-import java.util.LinkedHashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
+import java.text.NumberFormat;
+import java.util.*;
Review comment:
The style check passed without problem.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r410498305
##########
File path: core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
##########
@@ -118,6 +118,11 @@ public static Logger getSqlToRelTracer() {
return LoggerFactory.getLogger("org.apache.calcite.sql2rel");
}
+ public static Logger getRuleAttemptsTracer() {
+ return LoggerFactory.getLogger(
+ "org.apache.calcite.plan.AbstractRelOptPlanner.RuleAttemptsListener");
Review comment:
I don't want to break from the convention that we use full class name as logger name. There are already a couple of hard coded class names there. I personally don't think it's a problem.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r409861620
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
Review comment:
Ok, now I sort them by number of attempts descending, then by elapsed time descending,
then by rule name ascending.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
xndai commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407614640
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -96,6 +101,11 @@ protected AbstractRelOptPlanner(RelOptCostFactory costFactory,
// these types, but some operands may use them.
classes.add(RelNode.class);
classes.add(RelSubset.class);
+
+ if (LOGGER.isDebugEnabled()) {
+ this.ruleAttemptsListener = new RuleAttemptsListener();
Review comment:
I don't think we need a separate category just for the rule attempts. IMO it makes more sense to put them in DEBUG level log, together with the best plan and provenance map. And the verbose rule firing and transformation messages should really be TRACE.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407325396
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/VolcanoPlanner.java
##########
@@ -64,19 +45,8 @@
import java.io.PrintWriter;
import java.io.StringWriter;
-import java.util.ArrayDeque;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Comparator;
-import java.util.Deque;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.IdentityHashMap;
-import java.util.Iterator;
-import java.util.LinkedHashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
+import java.text.NumberFormat;
+import java.util.*;
Review comment:
Avoid to import star which is a bad code practice.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
vlsi commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407366072
##########
File path: core/src/main/java/org/apache/calcite/plan/AbstractRelOptPlanner.java
##########
@@ -453,4 +467,63 @@ protected MulticastRelOptListener getListener() {
: Collections.singletonList(relType);
return Pair.of(digest, v);
}
+
+ /** Listener for counting the attempts of each rule. Only enabled under DEBUG level.*/
+ private class RuleAttemptsListener implements RelOptListener {
+ private long beforeTimestamp;
+ private Map<String, Pair<Long, Long>> ruleAttempts;
+
+
+ RuleAttemptsListener() {
+ ruleAttempts = new HashMap<>();
+ }
+
+ @Override public void relEquivalenceFound(RelEquivalenceEvent event) {
+ }
+
+ @Override public void ruleAttempted(RuleAttemptedEvent event) {
+ if (event.isBefore()) {
+ this.beforeTimestamp = System.nanoTime();
+ } else {
+ long elapsed = (System.nanoTime() - this.beforeTimestamp) / 1000;
+ String rule = event.getRuleCall().getRule().toString();
+ if (ruleAttempts.containsKey(rule)) {
+ Pair<Long, Long> p = ruleAttempts.get(rule);
+ ruleAttempts.put(rule, Pair.of(p.left + 1, p.right + elapsed));
+ } else {
+ ruleAttempts.put(rule, Pair.of(1L, elapsed));
+ }
+ }
+ }
+
+ @Override public void ruleProductionSucceeded(RuleProductionEvent event) {
+ }
+
+ @Override public void relDiscarded(RelDiscardedEvent event) {
+ }
+
+ @Override public void relChosen(RelChosenEvent event) {
+ }
+
+ public String dump() {
+ // Sort rules by number of attempts
+ List<Map.Entry<String, Pair<Long, Long>>> list =
+ new ArrayList<>(this.ruleAttempts.entrySet());
+ Collections.sort(list,
+ (left, right) -> right.getValue().left.compareTo(left.getValue().left));
+
+ // Print out rule attempts and time
+ StringBuilder sb = new StringBuilder();
+ sb.append(String
+ .format(Locale.ROOT, "%n%-60s%20s%20s%n", "Rules", "Attempts", "Time (us)"));
+ for (Map.Entry<String, Pair<Long, Long>> entry : list) {
+ sb.append(
+ String.format(Locale.ROOT, "%-60s%20s%20s%n",
+ entry.getKey(),
+ NumberFormat.getNumberInstance(Locale.US).format(entry.getValue().left),
+ NumberFormat.getNumberInstance(Locale.US).format(entry.getValue().right)));
Review comment:
Please move `NumberFormat.getNumberInstance(Locale.US)` out of the loop
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [calcite] danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
Posted by GitBox <gi...@apache.org>.
danny0405 commented on a change in pull request #1910: [CALCITE-3915] Add rule listener to report rule attempts and time at …
URL: https://github.com/apache/calcite/pull/1910#discussion_r407325507
##########
File path: core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java
##########
@@ -196,7 +196,7 @@ VolcanoRuleMatch popMatch(VolcanoPlannerPhase phase) {
phaseMatchList.matchMap.remove(
planner.getSubset(match.rels[0]), match);
- LOGGER.debug("Pop match: {}", match);
+ LOGGER.trace("Pop match: {}", match);
return match;
Review comment:
Any strong reason why switch from `DEBUG` to `TRACE` ?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services