Skip to content

Include stats for each planner phase in EXPLAIN metrics #3512

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 9 commits into
base: main
Choose a base branch
from
Open

Include stats for each planner phase in EXPLAIN metrics #3512

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
12b5817
Introduce new timers for the different phases of the Cascades planner
hazefully Jul 29, 2025
260e2b1
Revert "Introduce new timers for the different phases of the Cascades…
hazefully Aug 7, 2025
2582ff8
Split the Cascades Debugger interface around stats and symbols
hazefully Aug 7, 2025
bdf2e16
Extract showing Debugger stats in the browser to a separate class
hazefully Aug 7, 2025
cf9848b
Group Debugger events by PlannerPhase in stats
hazefully Aug 7, 2025
a9edd0f
Include planner phase specifc metrics in EXPLAIN result
hazefully Aug 7, 2025
2ee4763
Add new lightweight debugger implementation
hazefully Aug 7, 2025
f35f7aa
Update doc comments
hazefully Aug 8, 2025
b53e042
Fix bug in StatsMaps for events without a state
hazefully Aug 8, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 14 additions & 13 deletions ...core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger.Location;
import com.apple.foundationdb.record.query.plan.cascades.debug.RestartException;
import com.apple.foundationdb.record.query.plan.cascades.debug.StatsDebugger;
import com.apple.foundationdb.record.query.plan.cascades.explain.ExplainPlanVisitor;
import com.apple.foundationdb.record.query.plan.cascades.explain.PlannerGraphVisitor;
import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression;
Expand Down Expand Up @@ -331,7 +332,7 @@ public QueryPlanResult planQuery(@Nonnull final RecordQuery query,
.put(QueryPlanInfoKeys.MAX_TASK_QUEUE_SIZE, maxQueueSize)
.put(QueryPlanInfoKeys.CONSTRAINTS, constraints)
.put(QueryPlanInfoKeys.STATS_MAPS,
Debugger.getDebuggerMaybe().flatMap(Debugger::getStatsMaps)
StatsDebugger.getDebuggerMaybe().flatMap(StatsDebugger::getStatsMaps)
.orElse(null))
.build();
return new QueryPlanResult(plan, info);
Expand Down Expand Up @@ -375,8 +376,8 @@ public QueryPlanResult planGraph(@Nonnull final Supplier<Reference> referenceSup
QueryPlanInfo.newBuilder()
.put(QueryPlanInfoKeys.CONSTRAINTS, constraints)
.put(QueryPlanInfoKeys.STATS_MAPS,
Debugger.getDebuggerMaybe()
.flatMap(Debugger::getStatsMaps).orElse(null))
StatsDebugger.getDebuggerMaybe().flatMap(StatsDebugger::getStatsMaps)
.orElse(null))
.build());
} finally {
Debugger.withDebugger(Debugger::onDone);
Expand Down Expand Up @@ -425,7 +426,7 @@ private void planPartial(@Nonnull final Supplier<Reference> referenceSupplier,
}
taskCount++;

Debugger.withDebugger(debugger -> debugger.onEvent(
StatsDebugger.withDebugger(debugger -> debugger.onEvent(
new Debugger.ExecutingTaskEvent(currentRoot, taskStack, Location.BEGIN,
Objects.requireNonNull(taskStack.peek()))));
Task nextTask = taskStack.pop();
Expand All @@ -434,7 +435,7 @@ private void planPartial(@Nonnull final Supplier<Reference> referenceSupplier,
logger.trace(KeyValueLogMessage.of("executing task", "nextTask", nextTask.toString()));
}

Debugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.BEGIN)));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.BEGIN)));
try {
nextTask.execute();
Debugger.sanityCheck(() -> {
Expand All @@ -454,7 +455,7 @@ private void planPartial(@Nonnull final Supplier<Reference> referenceSupplier,
});

} finally {
Debugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.END)));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.END)));
}

if (logger.isTraceEnabled()) {
Expand All @@ -469,7 +470,7 @@ private void planPartial(@Nonnull final Supplier<Reference> referenceSupplier,
.addLogInfo(LogMessageKeys.TASK_QUEUE_SIZE, taskStack.size());
}
} finally {
Debugger.withDebugger(debugger -> debugger.onEvent(
StatsDebugger.withDebugger(debugger -> debugger.onEvent(
new Debugger.ExecutingTaskEvent(currentRoot, taskStack, Location.END, nextTask)));
}
} catch (final RestartException restartException) {
Expand Down Expand Up @@ -1006,14 +1007,14 @@ public void execute() {
}
// we notify the debugger (if installed) that the transform task is succeeding and
// about begin and end of the rule call event
Debugger.withDebugger(debugger -> debugger.onEvent(toTaskEvent(Location.MATCH_PRE)));
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger -> debugger.onEvent(toTaskEvent(Location.MATCH_PRE)));
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(new Debugger.TransformRuleCallEvent(plannerPhase, currentRoot,
taskStack, Location.BEGIN, group, getBindable(), rule, ruleCall)));
try {
executeRuleCall(ruleCall);
} finally {
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(new Debugger.TransformRuleCallEvent(plannerPhase, currentRoot,
taskStack, Location.END, group, getBindable(), rule, ruleCall)));
}
Expand All @@ -1033,21 +1034,21 @@ protected void executeRuleCall(@Nonnull CascadesRuleCall ruleCall) {
// Handle produced artifacts (through yield...() calls)
//
for (final PartialMatch newPartialMatch : ruleCall.getNewPartialMatches()) {
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(new Debugger.TransformRuleCallEvent(plannerPhase, currentRoot, taskStack,
Location.YIELD, group, getBindable(), rule, ruleCall)));
taskStack.push(new AdjustMatch(getPlannerPhase(), getGroup(), getExpression(), newPartialMatch));
}

for (final RelationalExpression newExpression : ruleCall.getNewFinalExpressions()) {
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(new Debugger.TransformRuleCallEvent(plannerPhase, currentRoot, taskStack,
Location.YIELD, group, getBindable(), rule, ruleCall)));
exploreExpressionAndOptimizeInputs(plannerPhase, getGroup(), newExpression, true);
}

for (final RelationalExpression newExpression : ruleCall.getNewExploratoryExpressions()) {
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(new Debugger.TransformRuleCallEvent(plannerPhase, currentRoot, taskStack,
Location.YIELD, group, getBindable(), rule, ruleCall)));
exploreExpression(plannerPhase, group, newExpression, true);
Expand Down
21 changes: 11 additions & 10 deletions ...ore/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesRuleCall.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
import com.apple.foundationdb.record.query.plan.cascades.Quantifiers.AliasResolver;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger.InsertIntoMemoEvent;
import com.apple.foundationdb.record.query.plan.cascades.debug.StatsDebugger;
import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression;
import com.apple.foundationdb.record.query.plan.cascades.matching.structure.PlannerBindings;
import com.apple.foundationdb.record.query.plan.plans.RecordQueryPlan;
Expand Down Expand Up @@ -185,7 +186,7 @@ public <T> void pushConstraint(@Nonnull final Reference reference,
@Override
public void emitEvent(@Nonnull final Debugger.Location location) {
Verify.verify(location != Debugger.Location.BEGIN && location != Debugger.Location.END);
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(
new Debugger.TransformRuleCallEvent(plannerPhase, root, taskStack, location, root,
bindings.get(rule.getMatcher()), rule, this)));
Expand Down Expand Up @@ -295,7 +296,7 @@ public EvaluationContext getEvaluationContext() {
@Nonnull
private Reference addNewReference(@Nonnull final Reference newRef) {
for (RelationalExpression expression : newRef.getAllMemberExpressions()) {
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.newExp(expression)));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.newExp(expression)));
traversal.addExpression(newRef, expression);
}
newReferences.add(newRef);
Expand Down Expand Up @@ -352,7 +353,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection<? exten
// least one variation) or it will be a new reference, but that reference must be missing at least
// one child from the first variation and therefore cannot be reused
//
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin()));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin()));
try {
Preconditions.checkArgument(expressions.stream().noneMatch(expression -> expression instanceof RecordQueryPlan));

Expand Down Expand Up @@ -412,7 +413,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection<? exten
if (!existingRefs.isEmpty()) {
Reference existingReference = existingRefs.get(0);
expressions.forEach(expr ->
Debugger.withDebugger(debugger ->
StatsDebugger.withDebugger(debugger ->
debugger.onEvent(InsertIntoMemoEvent.reusedExpWithReferences(expr, existingRefs))));
Verify.verify(existingReference != this.root);
return existingReference;
Expand All @@ -421,7 +422,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection<? exten
// If we didn't find one, create a new reference and add it to the memo
return addNewReference(Reference.ofExploratoryExpressions(plannerPhase.getTargetPlannerStage(), expressions));
} finally {
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end()));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end()));
}
}

Expand All @@ -436,7 +437,7 @@ private boolean isEligibleForReuse(@Nonnull Set<CorrelationIdentifier> requiredC

@Nonnull
private Reference memoizeLeafExpressions(@Nonnull final Collection<? extends RelationalExpression> expressions) {
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin()));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin()));
try {
Preconditions.checkArgument(expressions.stream()
.allMatch(expression -> !(expression instanceof RecordQueryPlan) && expression.getQuantifiers().isEmpty()));
Expand All @@ -450,15 +451,15 @@ private Reference memoizeLeafExpressions(@Nonnull final Collection<? extends Rel
}
if (leafRef.containsAllInMemo(expressions, AliasMap.emptyMap(), false)) {
for (RelationalExpression expression : expressions) {
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.reusedExp(expression)));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.reusedExp(expression)));
}
return leafRef;
}
}

return addNewReference(Reference.ofExploratoryExpressions(plannerPhase.getTargetPlannerStage(), expressions));
} finally {
Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end()));
StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end()));
}
}

Expand Down Expand Up @@ -534,14 +535,14 @@ private Reference memoizeExpressionsExactly(@Nonnull final Collection<? extends
@Nonnull BiFunction<Set<? extends RelationalExpression>, Set<? extends RelationalExpression>, Reference> referenceCreator) {
final var allExpressions =
Iterables.concat(exploratoryExpressions, finalExpressions);
Debugger.withDebugger(debugger -> allExpressions.forEach(
StatsDebugger.withDebugger(debugger -> allExpressions.forEach(
expression -> debugger.onEvent(InsertIntoMemoEvent.begin())));
try {
final var exploratoryExpressionSet = new LinkedIdentitySet<>(exploratoryExpressions);
final var finalExpressionSet = new LinkedIdentitySet<>(finalExpressions);
return addNewReference(referenceCreator.apply(exploratoryExpressionSet, finalExpressionSet));
} finally {
Debugger.withDebugger(debugger -> allExpressions.forEach(
StatsDebugger.withDebugger(debugger -> allExpressions.forEach(
expression -> debugger.onEvent(InsertIntoMemoEvent.end())));
}
}
Expand Down
7 changes: 4 additions & 3 deletions ...rc/main/java/com/apple/foundationdb/record/query/plan/cascades/CorrelationIdentifier.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@

import com.apple.foundationdb.annotation.API;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger;
import com.apple.foundationdb.record.query.plan.cascades.debug.SymbolDebugger;
import com.apple.foundationdb.record.util.ProtoUtils;
import com.google.common.collect.ImmutableSet;

Expand Down Expand Up @@ -88,10 +89,10 @@ public static CorrelationIdentifier uniqueID(@Nonnull final Class<?> clazz) {
@Nonnull
public static CorrelationIdentifier uniqueID(@Nonnull final Class<?> clazz, @Nonnull final String prefix) {
final CorrelationIdentifier id =
Debugger.getIndexOptional(clazz)
SymbolDebugger.getIndexOptional(clazz)
.map(i -> CorrelationIdentifier.of(prefix + i))
.orElseGet(() -> new CorrelationIdentifier(ProtoUtils.uniqueName(prefix)));
Debugger.updateIndex(clazz, i -> i + 1);
SymbolDebugger.updateIndex(clazz, i -> i + 1);
return id;
}

Expand All @@ -106,7 +107,7 @@ public static CorrelationIdentifier uniqueID(@Nonnull final Class<?> clazz, @Non
*/
@Nonnull
public static CorrelationIdentifier uniqueSingletonID(@Nonnull final UUID singleton, @Nonnull final String prefix) {
return Debugger.getOrRegisterSingleton(singleton)
return SymbolDebugger.getOrRegisterSingleton(singleton)
.map(index -> new CorrelationIdentifier(prefix + index))
.orElseGet(() -> new CorrelationIdentifier(singleton.toString()));
}
Expand Down
4 changes: 2 additions & 2 deletions ...java/com/apple/foundationdb/record/query/plan/cascades/PrimaryAccessExpansionVisitor.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
import com.apple.foundationdb.annotation.SpotBugsSuppressWarnings;
import com.apple.foundationdb.record.metadata.RecordType;
import com.apple.foundationdb.record.metadata.expressions.KeyExpression;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger;
import com.apple.foundationdb.record.query.plan.cascades.debug.SymbolDebugger;
import com.apple.foundationdb.record.query.plan.cascades.expressions.MatchableSortExpression;
import com.apple.foundationdb.record.query.plan.cascades.predicates.PredicateWithValueAndRanges;
import com.google.common.collect.ImmutableList;
Expand Down Expand Up @@ -58,7 +58,7 @@ public PrimaryScanMatchCandidate expand(@Nonnull final Supplier<Quantifier.ForEa
@Nullable final KeyExpression primaryKey,
final boolean isReverse) {
Objects.requireNonNull(primaryKey);
Debugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0);
SymbolDebugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0);

final var baseQuantifier = baseQuantifierSupplier.get();

Expand Down
4 changes: 2 additions & 2 deletions ...ayer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Quantifier.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
import com.apple.foundationdb.record.PlanSerializable;
import com.apple.foundationdb.record.PlanSerializationContext;
import com.apple.foundationdb.record.planprotos.PPhysicalQuantifier;
import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger;
import com.apple.foundationdb.record.query.plan.cascades.debug.SymbolDebugger;
import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression;
import com.apple.foundationdb.record.query.plan.cascades.typing.Type;
import com.apple.foundationdb.record.query.plan.cascades.typing.Type.Record.Field;
Expand Down Expand Up @@ -625,7 +625,7 @@ protected Quantifier(@Nonnull final CorrelationIdentifier alias) {
this.flowedColumnsSupplier = Suppliers.memoize(this::computeFlowedColumns);
this.flowedValuesSupplier = Suppliers.memoize(this::computeFlowedValues);
// Call debugger hook for this new quantifier.
Debugger.registerQuantifier(this);
SymbolDebugger.registerQuantifier(this);
}

@Nonnull
Expand Down
Loading