diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java index fb9f7b51a0..9ba4796fa2 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesPlanner.java @@ -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; @@ -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); @@ -375,8 +376,8 @@ public QueryPlanResult planGraph(@Nonnull final Supplier 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); @@ -425,7 +426,7 @@ private void planPartial(@Nonnull final Supplier 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(); @@ -434,7 +435,7 @@ private void planPartial(@Nonnull final Supplier 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(() -> { @@ -454,7 +455,7 @@ private void planPartial(@Nonnull final Supplier referenceSupplier, }); } finally { - Debugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.END))); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(nextTask.toTaskEvent(Location.END))); } if (logger.isTraceEnabled()) { @@ -469,7 +470,7 @@ private void planPartial(@Nonnull final Supplier 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) { @@ -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))); } @@ -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); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesRuleCall.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesRuleCall.java index d79081a5cb..ced46a3a10 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesRuleCall.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CascadesRuleCall.java @@ -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; @@ -185,7 +186,7 @@ public 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))); @@ -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); @@ -352,7 +353,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection debugger.onEvent(InsertIntoMemoEvent.begin())); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin())); try { Preconditions.checkArgument(expressions.stream().noneMatch(expression -> expression instanceof RecordQueryPlan)); @@ -412,7 +413,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection - Debugger.withDebugger(debugger -> + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.reusedExpWithReferences(expr, existingRefs)))); Verify.verify(existingReference != this.root); return existingReference; @@ -421,7 +422,7 @@ public Reference memoizeExploratoryExpressions(@Nonnull final Collection debugger.onEvent(InsertIntoMemoEvent.end())); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end())); } } @@ -436,7 +437,7 @@ private boolean isEligibleForReuse(@Nonnull Set requiredC @Nonnull private Reference memoizeLeafExpressions(@Nonnull final Collection 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())); @@ -450,7 +451,7 @@ private Reference memoizeLeafExpressions(@Nonnull final Collection debugger.onEvent(InsertIntoMemoEvent.reusedExp(expression))); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.reusedExp(expression))); } return leafRef; } @@ -458,7 +459,7 @@ private Reference memoizeLeafExpressions(@Nonnull final Collection debugger.onEvent(InsertIntoMemoEvent.end())); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end())); } } @@ -534,14 +535,14 @@ private Reference memoizeExpressionsExactly(@Nonnull final Collection, Set, 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()))); } } diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CorrelationIdentifier.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CorrelationIdentifier.java index 72dc45bcb8..498fd7d426 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CorrelationIdentifier.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/CorrelationIdentifier.java @@ -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; @@ -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; } @@ -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())); } diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/PrimaryAccessExpansionVisitor.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/PrimaryAccessExpansionVisitor.java index cd1bfe193e..82c820ed15 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/PrimaryAccessExpansionVisitor.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/PrimaryAccessExpansionVisitor.java @@ -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; @@ -58,7 +58,7 @@ public PrimaryScanMatchCandidate expand(@Nonnull final Supplier 0); + SymbolDebugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0); final var baseQuantifier = baseQuantifierSupplier.get(); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Quantifier.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Quantifier.java index d40fdee0bd..4e259f891b 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Quantifier.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Quantifier.java @@ -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; @@ -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 diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Reference.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Reference.java index d8ede8046a..b897e2fbfa 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Reference.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/Reference.java @@ -25,6 +25,8 @@ import com.apple.foundationdb.record.query.plan.HeuristicPlanner; 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.debug.SymbolDebugger; import com.apple.foundationdb.record.query.plan.cascades.explain.PlannerGraphVisitor; import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression; import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpressionWithChildren; @@ -179,7 +181,7 @@ private Reference(@Nonnull final PlannerStage plannerStage, finalExpressions.forEach(finalExpression -> propertiesMap.add(finalExpression)); this.allMembersView = exploratoryMembers.concatExpressions(finalMembers); // Call debugger hook for this new reference. - Debugger.registerReference(this); + SymbolDebugger.registerReference(this); } @Nonnull @@ -325,10 +327,10 @@ public boolean insertFinalExpression(@Nonnull final RelationalExpression newValu private boolean insert(@Nonnull final RelationalExpression newExpression, final boolean isFinal, @Nullable final Map, ?> precomputedPropertiesMap) { - Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin())); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.begin())); try { final boolean containsInMemo = containsInMemo(newExpression, isFinal); - Debugger.withDebugger(debugger -> { + StatsDebugger.withDebugger(debugger -> { if (containsInMemo) { debugger.onEvent(InsertIntoMemoEvent.reusedExpWithReferences(newExpression, ImmutableList.of(this))); } else { @@ -341,7 +343,7 @@ private boolean insert(@Nonnull final RelationalExpression newExpression, } return false; } finally { - Debugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end())); + StatsDebugger.withDebugger(debugger -> debugger.onEvent(InsertIntoMemoEvent.end())); } } @@ -359,7 +361,7 @@ private void insertUnchecked(@Nonnull final RelationalExpression newExpression, final boolean isFinal, @Nullable final Map, ?> precomputedPropertiesMap) { // Call debugger hook to potentially register this new expression. - Debugger.registerExpression(newExpression); + SymbolDebugger.registerExpression(newExpression); Debugger.sanityCheck(() -> Verify.verify(getTotalMembersSize() == 0 || getResultType().equals(newExpression.getResultType()))); @@ -627,7 +629,7 @@ public U acceptVisitor(@Nonnull SimpleExpressionVisitor simpleExpressionV @Override public String toString() { - return Debugger.mapDebugger(debugger -> debugger.nameForObject(this) + "[" + + return SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(this) + "[" + getAllMemberExpressions().stream() .map(debugger::nameForObject) .collect(Collectors.joining(",")) + "]") @@ -856,8 +858,8 @@ public static Reference of(@Nonnull final PlannerStage plannerStage, @Nonnull final Collection exploratoryExpressions, @Nonnull final Collection finalExpressions) { // Call debugger hook to potentially register this new expression. - exploratoryExpressions.forEach(Debugger::registerExpression); - finalExpressions.forEach(Debugger::registerExpression); + exploratoryExpressions.forEach(SymbolDebugger::registerExpression); + finalExpressions.forEach(SymbolDebugger::registerExpression); return new Reference(plannerStage, new LinkedIdentitySet<>(exploratoryExpressions), new LinkedIdentitySet<>(finalExpressions)); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/References.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/References.java index d2ed48195e..df5f632d42 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/References.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/References.java @@ -23,6 +23,7 @@ import com.apple.foundationdb.record.RecordCoreException; import com.apple.foundationdb.record.query.combinatorics.TopologicalSort; import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger; +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.expressions.RelationalExpressionWithChildren; import com.apple.foundationdb.record.query.plan.cascades.values.translation.TranslationMap; @@ -187,14 +188,14 @@ private static void rebaseGraph(@Nonnull final Memoizer memoizer, @Nonnull final } else { translatedExpression = expression.translateCorrelations(translationMap, shouldSimplifyValues, translatedQuantifiers); - Debugger.withDebugger(debugger -> debugger.onEvent( + StatsDebugger.withDebugger(debugger -> debugger.onEvent( new Debugger.TranslateCorrelationsEvent(translatedExpression, Debugger.Location.COUNT))); allMembersSame = false; } } else { translatedExpression = expression.translateCorrelations(translationMap, shouldSimplifyValues, translatedQuantifiers); - Debugger.withDebugger(debugger -> debugger.onEvent( + StatsDebugger.withDebugger(debugger -> debugger.onEvent( new Debugger.TranslateCorrelationsEvent(translatedExpression, Debugger.Location.COUNT))); allMembersSame = false; } diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/ValueIndexExpansionVisitor.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/ValueIndexExpansionVisitor.java index 48361388c5..0d1ff32998 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/ValueIndexExpansionVisitor.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/ValueIndexExpansionVisitor.java @@ -27,7 +27,7 @@ import com.apple.foundationdb.record.metadata.expressions.GroupingKeyExpression; import com.apple.foundationdb.record.metadata.expressions.KeyExpression; import com.apple.foundationdb.record.metadata.expressions.KeyWithValueExpression; -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.Placeholder; import com.apple.foundationdb.record.query.plan.cascades.predicates.PredicateWithValueAndRanges; @@ -86,7 +86,7 @@ public ValueIndexExpansionVisitor(@Nonnull Index index, @Nonnull Collection baseQuantifierSupplier, @Nullable final KeyExpression primaryKey, final boolean isReverse) { - Debugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0); + SymbolDebugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0); final var baseQuantifier = baseQuantifierSupplier.get(); final var allExpansionsBuilder = ImmutableList.builder(); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/WindowedIndexExpansionVisitor.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/WindowedIndexExpansionVisitor.java index 6c3ab093ca..9fe928f324 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/WindowedIndexExpansionVisitor.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/WindowedIndexExpansionVisitor.java @@ -26,7 +26,7 @@ import com.apple.foundationdb.record.metadata.expressions.GroupingKeyExpression; import com.apple.foundationdb.record.metadata.expressions.KeyExpression; import com.apple.foundationdb.record.query.expressions.Comparisons; -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.expressions.SelectExpression; import com.apple.foundationdb.record.query.plan.cascades.predicates.Placeholder; @@ -98,7 +98,7 @@ public MatchCandidate expand(@Nonnull final Supplier baseQua var rootExpression = index.getRootExpression(); Verify.verify(rootExpression instanceof GroupingKeyExpression); - Debugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0); + SymbolDebugger.updateIndex(PredicateWithValueAndRanges.class, old -> 0); final var allExpansionsBuilder = ImmutableList.builder(); final var baseQuantifier = baseQuantifierSupplier.get(); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Debugger.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Debugger.java index 5ec77a5df2..2630d4e054 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Debugger.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Debugger.java @@ -27,7 +27,6 @@ import com.apple.foundationdb.record.query.plan.cascades.PartialMatch; import com.apple.foundationdb.record.query.plan.cascades.PlanContext; import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; -import com.apple.foundationdb.record.query.plan.cascades.Quantifier; import com.apple.foundationdb.record.query.plan.cascades.Reference; import com.apple.foundationdb.record.query.plan.cascades.debug.eventprotos.PAbstractEventWithState; import com.apple.foundationdb.record.query.plan.cascades.debug.eventprotos.PAdjustMatchEvent; @@ -50,7 +49,6 @@ import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression; import com.google.common.base.Verify; import com.google.common.collect.ImmutableList; -import com.google.errorprone.annotations.CanIgnoreReturnValue; import com.google.protobuf.Message; import javax.annotation.Nonnull; @@ -61,7 +59,6 @@ import java.util.Optional; import java.util.function.Consumer; import java.util.function.Function; -import java.util.function.IntUnaryOperator; /** *

@@ -69,13 +66,15 @@ * As the planner is currently single-threaded as per planning of a query, we keep an instance of an implementor of * this class in the thread-local. (per-thread singleton). * The main mean of communication with the debugger is the set of statics defined within this interface. + * There are two interfaces that extend this interface which provides different debugging functionalities, + * see {@link StatsDebugger} and {@link SymbolDebugger} for more details. *

- * Debugging functionality should only be enabled in test cases, never in deployments. *

* In order to enable debugging capabilities, clients should use {@link #setDebugger} which sets a debugger to be used * for the current thread. Once set, the planner starts interacting with the debugger in order to communicate important * state changes, like begin of planning, end of planner, etc. *

+ * Certain debugger implementations should only be enabled in test cases, never in deployments. *

* Clients using the debugger should never hold on/manage/use an instance of a debugger directly. Instead, clients * should use {@link #withDebugger} and {@link #mapDebugger} to invoke methods on the currently installed debugger. @@ -162,11 +161,7 @@ static void sanityCheck(@Nonnull final Runnable runnable) { */ @Nonnull static Optional mapDebugger(@Nonnull final Function function) { - final Debugger debugger = getDebugger(); - if (debugger != null) { - return Optional.ofNullable(function.apply(debugger)); - } - return Optional.empty(); + return getDebuggerMaybe().map(function); } static void install() { @@ -181,56 +176,13 @@ static void show(@Nonnull final Reference ref) { withDebugger(debugger -> debugger.onShow(ref)); } - static Optional getIndexOptional(Class clazz) { - return mapDebugger(debugger -> debugger.onGetIndex(clazz)); - } - - @Nonnull - @CanIgnoreReturnValue - static Optional updateIndex(Class clazz, IntUnaryOperator updateFn) { - return mapDebugger(debugger -> debugger.onUpdateIndex(clazz, updateFn)); - } - - static void registerExpression(RelationalExpression expression) { - withDebugger(debugger -> debugger.onRegisterExpression(expression)); - } - - static void registerReference(Reference reference) { - withDebugger(debugger -> debugger.onRegisterReference(reference)); - } - - static void registerQuantifier(Quantifier quantifier) { - withDebugger(debugger -> debugger.onRegisterQuantifier(quantifier)); - } - - static Optional getOrRegisterSingleton(Object singleton) { - return mapDebugger(debugger -> debugger.onGetOrRegisterSingleton(singleton)); - } - - @Nullable - String nameForObject(@Nonnull Object object); - @Nullable PlanContext getPlanContext(); boolean isSane(); - void onEvent(Event event); - void onDone(); - int onGetIndex(@Nonnull Class clazz); - - int onUpdateIndex(@Nonnull Class clazz, @Nonnull IntUnaryOperator updateFn); - - void onRegisterExpression(@Nonnull RelationalExpression expression); - - void onRegisterReference(@Nonnull Reference reference); - - void onRegisterQuantifier(@Nonnull Quantifier quantifier); - - int onGetOrRegisterSingleton(@Nonnull Object singleton); - void onInstall(); void onSetup(); @@ -239,12 +191,6 @@ static Optional getOrRegisterSingleton(Object singleton) { void onQuery(String queryAsString, PlanContext planContext); - @SuppressWarnings("unused") // only used by debugger - String showStats(); - - @Nonnull - Optional getStatsMaps(); - /** * Shorthands to identify a kind of event. */ @@ -325,7 +271,7 @@ default PEvent toEventProto() { @Nonnull static PRegisteredRelationalExpression toExpressionProto(@Nonnull final RelationalExpression expression) { return PRegisteredRelationalExpression.newBuilder() - .setName(Debugger.mapDebugger(debugger -> debugger.nameForObject(expression)).orElseThrow()) + .setName(SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(expression)).orElseThrow()) .setSemanticHashCode(expression.semanticHashCode()) .build(); } @@ -333,7 +279,7 @@ static PRegisteredRelationalExpression toExpressionProto(@Nonnull final Relation @Nonnull static PRegisteredReference toReferenceProto(@Nonnull final Reference reference) { final var builder = PRegisteredReference.newBuilder() - .setName(Debugger.mapDebugger(debugger -> debugger.nameForObject(reference)).orElseThrow()); + .setName(SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(reference)).orElseThrow()); for (final var member : reference.getAllMemberExpressions()) { builder.addExpressions(toExpressionProto(member)); } @@ -1024,13 +970,13 @@ private InsertIntoMemoEvent(@Nonnull final Location location, @Nullable final RelationalExpression expression, @Nonnull final Collection reusedExpressionReferences) { if (expression != null) { - Debugger.registerExpression(expression); + SymbolDebugger.registerExpression(expression); } this.expression = expression; this.location = location; this.reusedExpressionReferences = ImmutableList.copyOf(reusedExpressionReferences); // Call debugger hook to potentially register this new reference. - this.reusedExpressionReferences.forEach(Debugger::registerReference); + this.reusedExpressionReferences.forEach(SymbolDebugger::registerReference); } @Override diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/DebuggerWithSymbolTables.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/DebuggerWithSymbolTables.java index a8f2bb8264..9aa067ba80 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/DebuggerWithSymbolTables.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/DebuggerWithSymbolTables.java @@ -60,17 +60,22 @@ import static com.apple.foundationdb.record.query.plan.cascades.properties.ReferencesAndDependenciesProperty.referencesAndDependencies; /** + *

* Implementation of a debugger that maintains symbol tables for easier human consumption e.g. in test cases and/or * while debugging. + *

+ * Instances of this debugger should only be enabled in test cases, never in deployments. */ @SuppressWarnings("PMD.SystemPrintln") -public class DebuggerWithSymbolTables implements Debugger { +public class DebuggerWithSymbolTables implements SymbolDebugger, StatsDebugger { private static final Logger logger = LoggerFactory.getLogger(DebuggerWithSymbolTables.class); private final boolean isSane; private final boolean isRecordEvents; private final Iterable prerecordedEventProtoIterable; - private final Deque stateStack; + private final Deque eventStateStack; + private final Deque symbolTablesStack; + @Nullable private String queryAsString; @Nullable @@ -84,14 +89,20 @@ private DebuggerWithSymbolTables(final boolean isSane, final boolean isRecordEve this.isRecordEvents = isRecordEvents; this.prerecordedEventProtoIterable = prerecordedEventsFileName == null ? null : eventProtosFromFile(prerecordedEventsFileName); - this.stateStack = new ArrayDeque<>(); + this.eventStateStack = new ArrayDeque<>(); + this.symbolTablesStack = new ArrayDeque<>(); this.planContext = null; this.singletonToIndexMap = Maps.newHashMap(); } @Nonnull - State getCurrentState() { - return Objects.requireNonNull(stateStack.peek()); + EventState getCurrentEventState() { + return Objects.requireNonNull(eventStateStack.peek()); + } + + @Nonnull + SymbolTables getCurrentSymbolState() { + return Objects.requireNonNull(symbolTablesStack.peek()); } @Nullable @@ -111,27 +122,27 @@ public boolean isSane() { @Override public int onGetIndex(@Nonnull final Class clazz) { - return getCurrentState().getIndex(clazz); + return getCurrentSymbolState().getIndex(clazz); } @Override public int onUpdateIndex(@Nonnull final Class clazz, @Nonnull final IntUnaryOperator updateFn) { - return getCurrentState().updateIndex(clazz, updateFn); + return getCurrentSymbolState().updateIndex(clazz, updateFn); } @Override public void onRegisterExpression(@Nonnull final RelationalExpression expression) { - getCurrentState().registerExpression(expression); + getCurrentSymbolState().registerExpression(expression); } @Override public void onRegisterReference(@Nonnull final Reference reference) { - getCurrentState().registerReference(reference); + getCurrentSymbolState().registerReference(reference); } @Override public void onRegisterQuantifier(@Nonnull final Quantifier quantifier) { - getCurrentState().registerQuantifier(quantifier); + getCurrentSymbolState().registerQuantifier(quantifier); } @Override @@ -157,7 +168,8 @@ public void onShow(@Nonnull final Reference ref) { @Override public void onQuery(@Nonnull final String recordQuery, @Nonnull final PlanContext planContext) { - this.stateStack.push(State.copyOf(getCurrentState())); + this.eventStateStack.push(EventState.copyOf(getCurrentEventState())); + this.symbolTablesStack.push(SymbolTables.copyOf(getCurrentSymbolState())); this.queryAsString = recordQuery; this.planContext = planContext; @@ -165,17 +177,20 @@ public void onQuery(@Nonnull final String recordQuery, @Nonnull final PlanContex } void restartState() { - stateStack.pop(); - stateStack.push(State.copyOf(getCurrentState())); + eventStateStack.pop(); + eventStateStack.push(EventState.copyOf(getCurrentEventState())); + + symbolTablesStack.pop(); + symbolTablesStack.push(SymbolTables.copyOf(getCurrentSymbolState())); } @Override @SuppressWarnings("PMD.GuardLogStatement") // false positive public void onEvent(final Event event) { - if ((queryAsString == null) || (planContext == null) || stateStack.isEmpty()) { + if ((queryAsString == null) || (planContext == null) || eventStateStack.isEmpty()) { return; } - getCurrentState().addCurrentEvent(event); + getCurrentEventState().addCurrentEvent(event); if (logger.isTraceEnabled()) { if (event.getLocation() == Location.END && event instanceof TransformRuleCallEvent) { final TransformRuleCallEvent transformRuleCallEvent = (TransformRuleCallEvent)event; @@ -237,7 +252,7 @@ boolean isValidEntityName(@Nonnull final String identifier) { @Nullable @Override public String nameForObject(@Nonnull final Object object) { - final State state = getCurrentState(); + final SymbolTables state = getCurrentSymbolState(); if (object instanceof RelationalExpression) { @Nullable final Integer id = state.getInvertedExpressionsCache().getIfPresent(object); return (id == null) ? null : "exp" + id; @@ -254,8 +269,8 @@ public String nameForObject(@Nonnull final Object object) { @Override public void onDone() { - if (!stateStack.isEmpty() && queryAsString != null) { - final var state = Objects.requireNonNull(stateStack.peek()); + if (!eventStateStack.isEmpty() && queryAsString != null) { + final var state = Objects.requireNonNull(eventStateStack.peek()); if (logger.isInfoEnabled()) { logger.info(KeyValueLogMessage.of("planning done", "query", Objects.requireNonNull(queryAsString).substring(0, Math.min(queryAsString.length(), 30)), @@ -323,28 +338,23 @@ protected PEvent computeNext() { }; } - @Override - public String showStats() { - State currentState = stateStack.peek(); - if (currentState != null) { - return currentState.showStats(); - } - return "no stats"; - } - @Nonnull @Override public Optional getStatsMaps() { - State currentState = stateStack.peek(); - if (currentState != null) { - return Optional.of(currentState.getStatsMaps()); + EventState currentEventState = eventStateStack.peek(); + if (currentEventState != null) { + return Optional.of(currentEventState.getStatsMaps()); } return Optional.empty(); } private void reset() { - this.stateStack.clear(); - this.stateStack.push(State.initial(isRecordEvents, isRecordEvents, prerecordedEventProtoIterable)); + this.eventStateStack.clear(); + this.eventStateStack.push(EventState.initial(isRecordEvents, isRecordEvents, prerecordedEventProtoIterable)); + + this.symbolTablesStack.clear(); + this.symbolTablesStack.push(new SymbolTables()); + this.planContext = null; this.queryAsString = null; } @@ -399,7 +409,7 @@ public static DebuggerWithSymbolTables withPrerecordedEvents(@Nonnull final Stri public static void printForEachExpression(@Nonnull final Reference root) { forEachExpression(root, expression -> { System.out.println("expression: " + - Debugger.mapDebugger(debugger -> debugger.nameForObject(expression)).orElseThrow() + "; " + + SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(expression)).orElseThrow() + "; " + "hashCodeWithoutChildren: " + expression.hashCodeWithoutChildren() + "explain: " + expression); }); } diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/EventState.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/EventState.java new file mode 100644 index 0000000000..8f4d75b3c4 --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/EventState.java @@ -0,0 +1,333 @@ +/* + * State.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import com.apple.foundationdb.record.RecordCoreException; +import com.apple.foundationdb.record.logging.KeyValueLogMessage; +import com.apple.foundationdb.record.query.plan.cascades.CascadesRule; +import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; +import com.apple.foundationdb.record.query.plan.cascades.debug.eventprotos.PEvent; +import com.apple.foundationdb.record.util.pair.Pair; +import com.google.common.base.Verify; +import com.google.common.collect.Lists; +import com.google.common.collect.Maps; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import javax.annotation.Nonnull; +import javax.annotation.Nullable; +import java.util.ArrayDeque; +import java.util.Collections; +import java.util.Deque; +import java.util.Iterator; +import java.util.LinkedHashMap; +import java.util.List; +import java.util.Map; +import java.util.Objects; + +/** + * A class used by different implementations of {@link StatsDebugger} to record {@link Debugger.Event} and produce + * stats (number of events, total time taken by events of a specific type, etc.) for the recorded events. + */ +@SuppressWarnings("PMD.SystemPrintln") +public class EventState { + @Nonnull + private static final Logger logger = LoggerFactory.getLogger(EventState.class); + + @Nullable protected final List events; + @Nullable protected final List eventProtos; + @Nullable protected final Iterable prerecordedEventProtoIterable; + @Nullable protected Iterator prerecordedEventProtoIterator; + + @Nonnull protected final Map, MutableStats> eventWithoutStateClassStatsMap; + @Nonnull protected final Map, MutableStats>> eventWithStateClassStatsMapByPlannerPhase; + + @Nonnull protected final Map>, MutableStats> plannerRuleClassStatsMap; + + @Nonnull protected final Deque, EventDurations>> eventProfilingStack; + + protected int currentTick; + protected final long startTs; + + public static EventState initial(final boolean isRecordEvents, final boolean isRecordEventProtos, + @Nullable Iterable prerecordedEventProtoIterable) { + return new EventState(isRecordEvents, isRecordEventProtos, prerecordedEventProtoIterable); + } + + public static EventState copyOf(final EventState source) { + return new EventState( + source.events == null ? null : Lists.newArrayList(source.events), + source.eventProtos == null ? null : Lists.newArrayList(source.eventProtos), + source.prerecordedEventProtoIterable, + Maps.newLinkedHashMap(source.eventWithoutStateClassStatsMap), + Maps.newEnumMap(source.eventWithStateClassStatsMapByPlannerPhase), + Maps.newLinkedHashMap(source.plannerRuleClassStatsMap), + new ArrayDeque<>(source.eventProfilingStack), + source.getCurrentTick(), + source.getStartTs()); + } + + protected EventState(final boolean isRecordEvents, final boolean isRecordEventProtos, + @Nullable final Iterable prerecordedEventProtoIterable) { + this( + isRecordEventProtos ? Lists.newArrayList() : null, + isRecordEvents ? Lists.newArrayList() : null, + prerecordedEventProtoIterable, + Maps.newLinkedHashMap(), + Maps.newEnumMap(PlannerPhase.class), + Maps.newLinkedHashMap(), + new ArrayDeque<>(), + -1, + System.nanoTime()); + } + + protected EventState( + @Nullable final List events, + @Nullable final List eventProtos, + @Nullable final Iterable prerecordedEventProtoIterable, + @Nonnull final Map, MutableStats> eventWithoutStateClassStatsMap, + @Nonnull final Map, MutableStats>> eventWithStateClassStatsMapByPlannerPhase, + @Nonnull final Map>, MutableStats> plannerRuleClassStatsMap, + @Nonnull final Deque, EventDurations>> eventProfilingStack, + final int currentTick, + final long startTs) { + + this.events = events; + this.eventProtos = eventProtos; + this.prerecordedEventProtoIterable = prerecordedEventProtoIterable; + this.prerecordedEventProtoIterator = prerecordedEventProtoIterable == null + ? null : prerecordedEventProtoIterable.iterator(); + this.eventWithoutStateClassStatsMap = eventWithoutStateClassStatsMap; + this.eventWithStateClassStatsMapByPlannerPhase = eventWithStateClassStatsMapByPlannerPhase; + this.plannerRuleClassStatsMap = plannerRuleClassStatsMap; + this.eventProfilingStack = eventProfilingStack; + this.currentTick = currentTick; + this.startTs = startTs; + } + + @Nullable + public List getEvents() { + return events; + } + + @Nullable + public List getEventProtos() { + return eventProtos; + } + + @Nullable + public Iterator getPrerecordedEventProtoIterator() { + return prerecordedEventProtoIterator; + } + + public int getCurrentTick() { + return currentTick; + } + + public long getStartTs() { + return startTs; + } + + + @SuppressWarnings("unchecked") + public void addCurrentEvent(@Nonnull final Debugger.Event event) { + if (events != null) { + events.add(event); + } + if (eventProtos != null || prerecordedEventProtoIterator != null) { + final var currentEventProto = event.toEventProto(); + if (prerecordedEventProtoIterator != null) { + verifyCurrentEventProto(currentEventProto); + } + if (eventProtos != null) { + eventProtos.add(currentEventProto); + } + } + + currentTick++; + final long currentTsInNs = System.nanoTime(); + + final Class currentEventClass = event.getClass(); + switch (event.getLocation()) { + case BEGIN: + eventProfilingStack.push(Pair.of(currentEventClass, new EventDurations(currentTsInNs))); + updateCounts(event); + break; + case END: + Pair, EventDurations> profilingPair = eventProfilingStack.pop(); + final Class eventClass = profilingPair.getKey(); + EventDurations eventDurations = profilingPair.getValue(); + if (logger.isWarnEnabled() && currentEventClass != eventClass) { + // + // This is a severe problem, however, we don't want to further increase the noise by + // throwing an exception here. + // + logger.warn(KeyValueLogMessage.of("unable to unwind stack properly", + "expected event class", eventClass.getSimpleName(), + "current event class", currentEventClass.getSimpleName())); + } + + final long totalTime = currentTsInNs - eventDurations.getStartTsInNs(); + final long ownTime = totalTime - eventDurations.getAdjustmentForOwnTimeInNs(); + + final MutableStats forEventClass = getEventStatsForEvent(event); + forEventClass.increaseTotalTimeInNs(totalTime); + forEventClass.increaseOwnTimeInNs(ownTime); + if (event instanceof Debugger.TransformRuleCallEvent) { + final CascadesRule rule = ((Debugger.TransformRuleCallEvent)event).getRule(); + final Class> ruleClass = (Class>)rule.getClass(); + final MutableStats forPlannerRuleClass = getEventStatsForPlannerRuleClass(ruleClass); + forPlannerRuleClass.increaseTotalTimeInNs(totalTime); + forPlannerRuleClass.increaseOwnTimeInNs(ownTime); + } + + // adjust the parent's own time info + profilingPair = eventProfilingStack.peek(); + if (profilingPair != null) { + eventDurations = profilingPair.getValue(); + eventDurations.increaseAdjustmentForOwnTimeInNs(totalTime); + } + break; + default: + updateCounts(event); + break; + } + } + + private void verifyCurrentEventProto(final PEvent currentEventProto) { + Objects.requireNonNull(prerecordedEventProtoIterator); + Verify.verify(prerecordedEventProtoIterator.hasNext(), + "ran out of prerecorded events"); + final var expectedProto = prerecordedEventProtoIterator.next(); + if (!currentEventProto.equals(expectedProto)) { + System.err.println("Mismatch found between prerecorded event and this event!"); + System.err.println("The following events prior to this event did match:"); + if (eventProtos != null) { + for (int i = 0; i < eventProtos.size(); i++) { + final var oldEventProto = eventProtos.get(i); + System.err.println(i + ": " + oldEventProto.getDescription() + "; " + oldEventProto.getShorthand()); + } + } + + System.err.println(); + System.err.println("The following event did not match:"); + System.err.println("Expected: " + expectedProto); + System.err.println("Actual: " + currentEventProto); + prerecordedEventProtoIterator = null; + throw new RecordCoreException("Planning event does not match prerecorded event"); + } + } + + @SuppressWarnings("unchecked") + private void updateCounts(@Nonnull final Debugger.Event event) { + final MutableStats forEventClass = getEventStatsForEvent(event); + forEventClass.increaseCount(event.getLocation(), 1L); + + if (event instanceof Debugger.EventWithRule) { + final CascadesRule rule = ((Debugger.EventWithRule)event).getRule(); + final Class> ruleClass = (Class>)rule.getClass(); + final MutableStats forPlannerRuleClass = getEventStatsForPlannerRuleClass(ruleClass); + forPlannerRuleClass.increaseCount(event.getLocation(), 1L); + } + } + + private MutableStats getEventStatsForEvent(@Nonnull Debugger.Event event) { + return (event instanceof Debugger.EventWithState) ? + getEventStatsForEventWithStateClassByPlannerPhase((Debugger.EventWithState)event) : + getEventStatsForEventWithoutStateClass(event.getClass()); + } + + private MutableStats getEventStatsForEventWithoutStateClass(@Nonnull Class eventClass) { + return eventWithoutStateClassStatsMap.compute(eventClass, (eC, mutableStats) -> mutableStats != null ? mutableStats : new MutableStats()); + } + + private MutableStats getEventStatsForEventWithStateClassByPlannerPhase(@Nonnull Debugger.EventWithState event) { + return eventWithStateClassStatsMapByPlannerPhase.computeIfAbsent(event.getPlannerPhase(), pP -> new LinkedHashMap<>()) + .computeIfAbsent(event.getClass(), (eC) -> new MutableStats()); + } + + private MutableStats getEventStatsForPlannerRuleClass(@Nonnull Class> plannerRuleClass) { + return plannerRuleClassStatsMap.computeIfAbsent(plannerRuleClass, (eC) -> new MutableStats()); + } + + @Nonnull + StatsMaps getStatsMaps() { + return new StatsMaps( + Collections.unmodifiableMap(eventWithoutStateClassStatsMap), + Collections.unmodifiableMap(eventWithStateClassStatsMapByPlannerPhase), + Collections.unmodifiableMap(plannerRuleClassStatsMap)); + } + + private static class MutableStats extends Stats { + public MutableStats() { + super(Maps.newLinkedHashMap(), 0L, 0L); + } + + public void setCount(@Nonnull Debugger.Location location, final long count) { + locationCountMap.put(location, count); + } + + public void increaseCount(@Nonnull Debugger.Location location, final long increase) { + setCount(location, getCount(location) + increase); + } + + public void setTotalTimeInNs(final long totalTimeInNs) { + this.totalTimeInNs = totalTimeInNs; + } + + public void increaseTotalTimeInNs(final long increaseInNs) { + setTotalTimeInNs(getTotalTimeInNs() + increaseInNs); + } + + public void setOwnTimeInNs(final long ownTimeInNs) { + this.ownTimeInNs = ownTimeInNs; + } + + public void increaseOwnTimeInNs(final long increaseInNs) { + setOwnTimeInNs(getOwnTimeInNs() + increaseInNs); + } + } + + private static class EventDurations { + private final long startTsInNs; + private long adjustmentForOwnTimeInNs; + + public EventDurations(final long startTsInNs) { + this.startTsInNs = startTsInNs; + } + + public long getStartTsInNs() { + return startTsInNs; + } + + public long getAdjustmentForOwnTimeInNs() { + return adjustmentForOwnTimeInNs; + } + + public void setAdjustmentForOwnTimeInNs(final long adjustmentForOwnTimeInNs) { + this.adjustmentForOwnTimeInNs = adjustmentForOwnTimeInNs; + } + + public void increaseAdjustmentForOwnTimeInNs(final long increaseInNs) { + setAdjustmentForOwnTimeInNs(getAdjustmentForOwnTimeInNs() + increaseInNs); + } + } +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/LightweightDebugger.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/LightweightDebugger.java new file mode 100644 index 0000000000..b387ae1e49 --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/LightweightDebugger.java @@ -0,0 +1,138 @@ +/* + * LightweightDebugger.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import com.apple.foundationdb.record.logging.KeyValueLogMessage; +import com.apple.foundationdb.record.query.plan.cascades.PlanContext; +import com.apple.foundationdb.record.query.plan.cascades.Reference; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import javax.annotation.Nonnull; +import javax.annotation.Nullable; +import java.util.Objects; +import java.util.Optional; +import java.util.concurrent.TimeUnit; + +/** + * Implementation of a lightweight debugger that only maintains debugging events for calculating {@link Stats} + * (i.e. it implements only the {@link StatsDebugger} interface). + * This debugger is safe for use in deployments. + */ +public class LightweightDebugger implements StatsDebugger { + private static final Logger logger = LoggerFactory.getLogger(LightweightDebugger.class); + + @Nullable + private EventState currentEventState; + @Nullable + private String queryAsString; + @Nullable + private PlanContext planContext; + + public LightweightDebugger() { + this.currentEventState = null; + this.planContext = null; + } + + @Nonnull + EventState getCurrentEventState() { + return Objects.requireNonNull(currentEventState); + } + + @Nullable + @Override + public PlanContext getPlanContext() { + return planContext; + } + + @Override + public boolean isSane() { + return true; + } + + @Override + public void onInstall() { + // do nothing + } + + @Override + public void onSetup() { + reset(); + } + + @Override + public void onShow(@Nonnull final Reference ref) { + // do nothing + } + + @Override + public void onQuery(@Nonnull final String recordQuery, @Nonnull final PlanContext planContext) { + reset(); + + this.queryAsString = recordQuery; + this.planContext = planContext; + + logQuery(); + } + + @Override + public void onEvent(final Debugger.Event event) { + if ((queryAsString == null) || (planContext == null) || (currentEventState == null)) { + return; + } + getCurrentEventState().addCurrentEvent(event); + } + + @Override + public void onDone() { + if (currentEventState != null && queryAsString != null) { + final var state = Objects.requireNonNull(currentEventState); + if (logger.isDebugEnabled()) { + logger.debug(KeyValueLogMessage.of("planning done", + "query", Objects.requireNonNull(queryAsString).substring(0, Math.min(queryAsString.length(), 30)), + "duration-in-ms", TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - state.getStartTs()), + "ticks", state.getCurrentTick())); + } + } + reset(); + } + + @Nonnull + @Override + public Optional getStatsMaps() { + if (currentEventState != null) { + return Optional.of(currentEventState.getStatsMaps()); + } + return Optional.empty(); + } + + private void reset() { + this.currentEventState = EventState.initial(false, false, null); + this.planContext = null; + this.queryAsString = null; + } + + void logQuery() { + if (logger.isDebugEnabled()) { + logger.debug(KeyValueLogMessage.of("planning started", "query", queryAsString)); + } + } +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/State.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/State.java deleted file mode 100644 index a39eb38661..0000000000 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/State.java +++ /dev/null @@ -1,515 +0,0 @@ -/* - * State.java - * - * This source file is part of the FoundationDB open source project - * - * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package com.apple.foundationdb.record.query.plan.cascades.debug; - -import com.apple.foundationdb.record.RecordCoreException; -import com.apple.foundationdb.record.logging.KeyValueLogMessage; -import com.apple.foundationdb.record.query.plan.cascades.CascadesRule; -import com.apple.foundationdb.record.query.plan.cascades.Quantifier; -import com.apple.foundationdb.record.query.plan.cascades.Reference; -import com.apple.foundationdb.record.query.plan.cascades.debug.eventprotos.PEvent; -import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression; -import com.apple.foundationdb.record.util.pair.Pair; -import com.google.common.base.Verify; -import com.google.common.cache.Cache; -import com.google.common.cache.CacheBuilder; -import com.google.common.collect.ImmutableMap; -import com.google.common.collect.Lists; -import com.google.common.collect.Maps; -import com.google.errorprone.annotations.CanIgnoreReturnValue; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import javax.annotation.Nonnull; -import javax.annotation.Nullable; -import java.util.ArrayDeque; -import java.util.Deque; -import java.util.Iterator; -import java.util.List; -import java.util.Locale; -import java.util.Map; -import java.util.Objects; -import java.util.concurrent.TimeUnit; -import java.util.function.IntUnaryOperator; - -@SuppressWarnings("PMD.SystemPrintln") -public class State { - @Nonnull - private static final Logger logger = LoggerFactory.getLogger(State.class); - - @Nonnull - private final Map, Integer> classToIndexMap; - @Nonnull - private final Cache expressionCache; - @Nonnull private final Cache invertedExpressionsCache; - @Nonnull private final Cache referenceCache; - @Nonnull private final Cache invertedReferenceCache; - @Nonnull private final Cache quantifierCache; - @Nonnull private final Cache invertedQuantifierCache; - - @Nullable private final List events; - @Nullable private final List eventProtos; - @Nullable private final Iterable prerecordedEventProtoIterable; - @Nullable private Iterator prerecordedEventProtoIterator; - - @Nonnull private final Map, MutableStats> eventClassStatsMap; - - @Nonnull private final Map>, MutableStats> plannerRuleClassStatsMap; - - @Nonnull private final Deque, EventDurations>> eventProfilingStack; - - private int currentTick; - private final long startTs; - - public static State initial(final boolean isRecordEvents, final boolean isRecordEventProtos, - @Nullable Iterable prerecordedEventProtoIterable) { - return new State(isRecordEvents, isRecordEventProtos, prerecordedEventProtoIterable); - } - - public static State copyOf(final State source) { - final Cache copyExpressionCache = CacheBuilder.newBuilder().weakValues().build(); - source.getExpressionCache().asMap().forEach(copyExpressionCache::put); - final Cache copyInvertedExpressionsCache = CacheBuilder.newBuilder().weakKeys().build(); - source.getInvertedExpressionsCache().asMap().forEach(copyInvertedExpressionsCache::put); - final Cache copyReferenceCache = CacheBuilder.newBuilder().weakValues().build(); - source.getReferenceCache().asMap().forEach(copyReferenceCache::put); - final Cache copyInvertedReferenceCache = CacheBuilder.newBuilder().weakKeys().build(); - source.getInvertedReferenceCache().asMap().forEach(copyInvertedReferenceCache::put); - final Cache copyQuantifierCache = CacheBuilder.newBuilder().weakValues().build(); - source.getQuantifierCache().asMap().forEach(copyQuantifierCache::put); - final Cache copyInvertedQuantifierCache = CacheBuilder.newBuilder().weakKeys().build(); - source.getInvertedQuantifierCache().asMap().forEach(copyInvertedQuantifierCache::put); - - return new State(source.getClassToIndexMap(), - copyExpressionCache, - copyInvertedExpressionsCache, - copyReferenceCache, - copyInvertedReferenceCache, - copyQuantifierCache, - copyInvertedQuantifierCache, - source.events == null ? null : Lists.newArrayList(source.events), - source.eventProtos == null ? null : Lists.newArrayList(source.eventProtos), - source.prerecordedEventProtoIterable, - Maps.newLinkedHashMap(source.eventClassStatsMap), - Maps.newLinkedHashMap(source.plannerRuleClassStatsMap), - new ArrayDeque<>(source.eventProfilingStack), - source.getCurrentTick(), - source.getStartTs()); - } - - private State(final boolean isRecordEvents, final boolean isRecordEventProtos, - @Nullable final Iterable prerecordedEventProtoIterable) { - this(Maps.newHashMap(), - CacheBuilder.newBuilder().weakValues().build(), - CacheBuilder.newBuilder().weakKeys().build(), - CacheBuilder.newBuilder().weakValues().build(), - CacheBuilder.newBuilder().weakKeys().build(), - CacheBuilder.newBuilder().weakValues().build(), - CacheBuilder.newBuilder().weakKeys().build(), - isRecordEventProtos ? Lists.newArrayList() : null, - isRecordEvents ? Lists.newArrayList() : null, - prerecordedEventProtoIterable, - Maps.newLinkedHashMap(), - Maps.newLinkedHashMap(), - new ArrayDeque<>(), - -1, - System.nanoTime()); - } - - private State(@Nonnull final Map, Integer> classToIndexMap, - @Nonnull final Cache expressionCache, - @Nonnull final Cache invertedExpressionsCache, - @Nonnull final Cache referenceCache, - @Nonnull final Cache invertedReferenceCache, - @Nonnull final Cache quantifierCache, - @Nonnull final Cache invertedQuantifierCache, - @Nullable final List events, - @Nullable final List eventProtos, - @Nullable final Iterable prerecordedEventProtoIterable, - @Nonnull final Map, MutableStats> eventClassStatsMap, - @Nonnull final Map>, MutableStats> plannerRuleClassStatsMap, - @Nonnull final Deque, EventDurations>> eventProfilingStack, - final int currentTick, - final long startTs) { - this.classToIndexMap = Maps.newHashMap(classToIndexMap); - this.expressionCache = expressionCache; - this.invertedExpressionsCache = invertedExpressionsCache; - this.referenceCache = referenceCache; - this.invertedReferenceCache = invertedReferenceCache; - this.quantifierCache = quantifierCache; - this.invertedQuantifierCache = invertedQuantifierCache; - this.events = events; - this.eventProtos = eventProtos; - this.prerecordedEventProtoIterable = prerecordedEventProtoIterable; - this.prerecordedEventProtoIterator = prerecordedEventProtoIterable == null - ? null : prerecordedEventProtoIterable.iterator(); - this.eventClassStatsMap = eventClassStatsMap; - this.plannerRuleClassStatsMap = plannerRuleClassStatsMap; - this.eventProfilingStack = eventProfilingStack; - this.currentTick = currentTick; - this.startTs = startTs; - } - - @Nonnull - private Map, Integer> getClassToIndexMap() { - return classToIndexMap; - } - - @Nonnull - public Cache getExpressionCache() { - return expressionCache; - } - - @Nonnull - public Cache getInvertedExpressionsCache() { - return invertedExpressionsCache; - } - - @Nonnull - public Cache getReferenceCache() { - return referenceCache; - } - - @Nonnull - public Cache getInvertedReferenceCache() { - return invertedReferenceCache; - } - - @Nonnull - public Cache getQuantifierCache() { - return quantifierCache; - } - - @Nonnull - public Cache getInvertedQuantifierCache() { - return invertedQuantifierCache; - } - - @Nullable - public List getEvents() { - return events; - } - - @Nullable - public List getEventProtos() { - return eventProtos; - } - - @Nullable - public Iterator getPrerecordedEventProtoIterator() { - return prerecordedEventProtoIterator; - } - - public int getCurrentTick() { - return currentTick; - } - - public long getStartTs() { - return startTs; - } - - public int getIndex(final Class clazz) { - return classToIndexMap.getOrDefault(clazz, 0); - } - - @CanIgnoreReturnValue - public int updateIndex(final Class clazz, IntUnaryOperator computeFn) { - return classToIndexMap.compute(clazz, (c, value) -> value == null ? computeFn.applyAsInt(0) : computeFn.applyAsInt(value)); - } - - public void registerExpression(final RelationalExpression expression) { - if (invertedExpressionsCache.getIfPresent(expression) == null) { - final int index = getIndex(RelationalExpression.class); - expressionCache.put(index, expression); - invertedExpressionsCache.put(expression, index); - updateIndex(RelationalExpression.class, i -> i + 1); - } - } - - public void registerReference(final Reference reference) { - if (invertedReferenceCache.getIfPresent(reference) == null) { - final int index = getIndex(Reference.class); - referenceCache.put(index, reference); - invertedReferenceCache.put(reference, index); - updateIndex(Reference.class, i -> i + 1); - } - } - - public void registerQuantifier(final Quantifier quantifier) { - if (invertedQuantifierCache.getIfPresent(quantifier) == null) { - final int index = getIndex(Quantifier.class); - quantifierCache.put(index, quantifier); - invertedQuantifierCache.put(quantifier, index); - updateIndex(Quantifier.class, i -> i + 1); - } - } - - @SuppressWarnings("unchecked") - public void addCurrentEvent(@Nonnull final Debugger.Event event) { - if (events != null) { - events.add(event); - } - if (eventProtos != null || prerecordedEventProtoIterator != null) { - final var currentEventProto = event.toEventProto(); - if (prerecordedEventProtoIterator != null) { - verifyCurrentEventProto(currentEventProto); - } - if (eventProtos != null) { - eventProtos.add(currentEventProto); - } - } - - currentTick++; - final long currentTsInNs = System.nanoTime(); - - final Class currentEventClass = event.getClass(); - switch (event.getLocation()) { - case BEGIN: - eventProfilingStack.push(Pair.of(currentEventClass, new EventDurations(currentTsInNs))); - updateCounts(event); - break; - case END: - Pair, EventDurations> profilingPair = eventProfilingStack.pop(); - final Class eventClass = profilingPair.getKey(); - EventDurations eventDurations = profilingPair.getValue(); - if (logger.isWarnEnabled() && currentEventClass != eventClass) { - // - // This is a severe problem, however, we don't want to further increase the noise by - // throwing an exception here. - // - logger.warn(KeyValueLogMessage.of("unable to unwind stack properly", - "expected event class", eventClass.getSimpleName(), - "current event class", currentEventClass.getSimpleName())); - } - - final long totalTime = currentTsInNs - eventDurations.getStartTsInNs(); - final long ownTime = totalTime - eventDurations.getAdjustmentForOwnTimeInNs(); - - final MutableStats forEventClass = getEventStatsForEventClass(currentEventClass); - forEventClass.increaseTotalTimeInNs(totalTime); - forEventClass.increaseOwnTimeInNs(ownTime); - if (event instanceof Debugger.TransformRuleCallEvent) { - final CascadesRule rule = ((Debugger.TransformRuleCallEvent)event).getRule(); - final Class> ruleClass = (Class>)rule.getClass(); - final MutableStats forPlannerRuleClass = getEventStatsForPlannerRuleClass(ruleClass); - forPlannerRuleClass.increaseTotalTimeInNs(totalTime); - forPlannerRuleClass.increaseOwnTimeInNs(ownTime); - } - - // adjust the parent's own time info - profilingPair = eventProfilingStack.peek(); - if (profilingPair != null) { - eventDurations = profilingPair.getValue(); - eventDurations.increaseAdjustmentForOwnTimeInNs(totalTime); - } - break; - default: - updateCounts(event); - break; - } - } - - private void verifyCurrentEventProto(final PEvent currentEventProto) { - Objects.requireNonNull(prerecordedEventProtoIterator); - Verify.verify(prerecordedEventProtoIterator.hasNext(), - "ran out of prerecorded events"); - final var expectedProto = prerecordedEventProtoIterator.next(); - if (!currentEventProto.equals(expectedProto)) { - System.err.println("Mismatch found between prerecorded event and this event!"); - System.err.println("The following events prior to this event did match:"); - if (eventProtos != null) { - for (int i = 0; i < eventProtos.size(); i++) { - final var oldEventProto = eventProtos.get(i); - System.err.println(i + ": " + oldEventProto.getDescription() + "; " + oldEventProto.getShorthand()); - } - } - - System.err.println(); - System.err.println("The following event did not match:"); - System.err.println("Expected: " + expectedProto); - System.err.println("Actual: " + currentEventProto); - prerecordedEventProtoIterator = null; - throw new RecordCoreException("Planning event does not match prerecorded event"); - } - } - - @SuppressWarnings("unchecked") - private void updateCounts(@Nonnull final Debugger.Event event) { - final MutableStats forEventClass = getEventStatsForEventClass(event.getClass()); - forEventClass.increaseCount(event.getLocation(), 1L); - if (event instanceof Debugger.EventWithRule) { - final CascadesRule rule = ((Debugger.EventWithRule)event).getRule(); - final Class> ruleClass = (Class>)rule.getClass(); - final MutableStats forPlannerRuleClass = getEventStatsForPlannerRuleClass(ruleClass); - forPlannerRuleClass.increaseCount(event.getLocation(), 1L); - } - } - - private MutableStats getEventStatsForEventClass(@Nonnull Class eventClass) { - return eventClassStatsMap.compute(eventClass, (eC, mutableStats) -> mutableStats != null ? mutableStats : new MutableStats()); - } - - private MutableStats getEventStatsForPlannerRuleClass(@Nonnull Class> plannerRuleClass) { - return plannerRuleClassStatsMap.compute(plannerRuleClass, (eC, mutableStats) -> mutableStats != null ? mutableStats : new MutableStats()); - } - - @Nonnull - StatsMaps getStatsMaps() { - return new StatsMaps(eventClassStatsMap, plannerRuleClassStatsMap); - } - - public String showStats() { - StringBuilder tableBuilder = new StringBuilder(); - tableBuilder.append(""); - tableHeader(tableBuilder, "Event"); - final ImmutableMap eventStatsMap = - eventClassStatsMap.entrySet() - .stream() - .map(entry -> Pair.of(entry.getKey().getSimpleName(), entry.getValue())) - .sorted(Map.Entry.comparingByKey()) - .collect(ImmutableMap.toImmutableMap(Pair::getKey, Pair::getValue)); - tableBody(tableBuilder, eventStatsMap); - tableBuilder.append("
"); - - final String eventProfilingString = tableBuilder.toString(); - - tableBuilder = new StringBuilder(); - tableBuilder.append(""); - tableHeader(tableBuilder, "Planner Rule"); - final ImmutableMap plannerRuleStatsMap = - plannerRuleClassStatsMap.entrySet() - .stream() - .map(entry -> Pair.of(entry.getKey().getSimpleName(), entry.getValue())) - .sorted(Map.Entry.comparingByKey()) - .collect(ImmutableMap.toImmutableMap(Pair::getKey, Pair::getValue)); - tableBody(tableBuilder, plannerRuleStatsMap); - tableBuilder.append("
"); - - final String plannerRuleProfilingString = tableBuilder.toString(); - - return BrowserHelper.browse("/showProfilingReport.html", - ImmutableMap.of("$EVENT_PROFILING", eventProfilingString, - "$PLANNER_RULE_PROFILING", plannerRuleProfilingString)); - } - - private void tableHeader(@Nonnull final StringBuilder stringBuilder, @Nonnull final String category) { - stringBuilder.append(""); - stringBuilder.append(""); - stringBuilder.append("").append(category).append(""); - stringBuilder.append("Location"); - stringBuilder.append("Count"); - stringBuilder.append("Total Time (micros)"); - stringBuilder.append("Average Time (micros)"); - stringBuilder.append("Total Own Time (micros)"); - stringBuilder.append("Average Own Time (micros)"); - stringBuilder.append(""); - stringBuilder.append(""); - } - - private void tableBody(@Nonnull final StringBuilder stringBuilder, @Nonnull final Map statsMap) { - stringBuilder.append(""); - for (final Map.Entry entry : statsMap.entrySet()) { - final MutableStats mutableStats = entry.getValue(); - for (final var locationEntry : mutableStats.getLocationCountMap().entrySet()) { - stringBuilder.append(""); - stringBuilder.append("").append(entry.getKey()).append(""); - if (locationEntry.getKey() == Debugger.Location.BEGIN) { - stringBuilder.append(""); - } else { - stringBuilder.append("").append(locationEntry.getKey().name()).append(""); - } - stringBuilder.append("").append(locationEntry.getValue()).append(""); - if (locationEntry.getKey() == Debugger.Location.BEGIN) { - stringBuilder.append("").append(formatNsInMicros(mutableStats.getTotalTimeInNs())).append(""); - stringBuilder.append("").append(formatNsInMicros(mutableStats.getTotalTimeInNs() / mutableStats.getCount(Debugger.Location.BEGIN))).append(""); - stringBuilder.append("").append(formatNsInMicros(mutableStats.getOwnTimeInNs())).append(""); - stringBuilder.append("").append(formatNsInMicros(mutableStats.getOwnTimeInNs() / mutableStats.getCount(Debugger.Location.BEGIN))).append(""); - } else { - stringBuilder.append(""); - stringBuilder.append(""); - } - stringBuilder.append(""); - } - } - stringBuilder.append(""); - } - - @Nonnull - private String formatNsInMicros(final long ns) { - final long micros = TimeUnit.NANOSECONDS.toMicros(ns); - return String.format(Locale.ROOT, "%,d", micros); - } - - private static class MutableStats extends Stats { - public MutableStats() { - super(Maps.newLinkedHashMap(), 0L, 0L); - } - - public void setCount(@Nonnull Debugger.Location location, final long count) { - locationCountMap.put(location, count); - } - - public void increaseCount(@Nonnull Debugger.Location location, final long increase) { - setCount(location, getCount(location) + increase); - } - - public void setTotalTimeInNs(final long totalTimeInNs) { - this.totalTimeInNs = totalTimeInNs; - } - - public void increaseTotalTimeInNs(final long increaseInNs) { - setTotalTimeInNs(getTotalTimeInNs() + increaseInNs); - } - - public void setOwnTimeInNs(final long ownTimeInNs) { - this.ownTimeInNs = ownTimeInNs; - } - - public void increaseOwnTimeInNs(final long increaseInNs) { - setOwnTimeInNs(getOwnTimeInNs() + increaseInNs); - } - } - - private static class EventDurations { - private final long startTsInNs; - private long adjustmentForOwnTimeInNs; - - public EventDurations(final long startTsInNs) { - this.startTsInNs = startTsInNs; - } - - public long getStartTsInNs() { - return startTsInNs; - } - - public long getAdjustmentForOwnTimeInNs() { - return adjustmentForOwnTimeInNs; - } - - public void setAdjustmentForOwnTimeInNs(final long adjustmentForOwnTimeInNs) { - this.adjustmentForOwnTimeInNs = adjustmentForOwnTimeInNs; - } - - public void increaseAdjustmentForOwnTimeInNs(final long increaseInNs) { - setAdjustmentForOwnTimeInNs(getAdjustmentForOwnTimeInNs() + increaseInNs); - } - } -} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Stats.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Stats.java index 43e7f8a44d..62cd044502 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Stats.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Stats.java @@ -24,6 +24,8 @@ import javax.annotation.Nonnull; import java.util.Map; +import java.util.Set; +import java.util.stream.Stream; public class Stats { @Nonnull @@ -61,4 +63,14 @@ public long getOwnTimeInNs() { public Stats toImmutable() { return new Stats(ImmutableMap.copyOf(locationCountMap), totalTimeInNs, ownTimeInNs); } + + public static Stats merge(final Stats first, final Stats second) { + return new Stats( + Stream.of(first.getLocationCountMap(), second.getLocationCountMap()) + .map(Map::entrySet) + .flatMap(Set::stream) + .collect(ImmutableMap.toImmutableMap(Map.Entry::getKey, Map.Entry::getValue, Long::sum)), + first.getTotalTimeInNs() + second.getTotalTimeInNs(), + first.getOwnTimeInNs() + second.getOwnTimeInNs()); + } } diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsDebugger.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsDebugger.java new file mode 100644 index 0000000000..96a9199bdf --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsDebugger.java @@ -0,0 +1,61 @@ +/* + * StatsDebugger.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import javax.annotation.Nonnull; +import java.util.Optional; +import java.util.function.Consumer; +import java.util.function.Function; + +/** + *

+ * This interface extends the {@link Debugger} interface and provides functionality related to + * recording instances of {@link Debugger.Event} and producing statistics based on these events + * in the form of {@link StatsMaps}. + *

+ * Similar to the {@link Debugger} interface, the main mean of communication with the debugger + * for operations related to recording events is the set of statics defined within this interface. + *

+ */ +public interface StatsDebugger extends Debugger { + @Nonnull + static Optional getDebuggerMaybe() { + final var debugger = Debugger.getDebugger(); + if (debugger instanceof StatsDebugger) { + return Optional.of((StatsDebugger)debugger); + } + return Optional.empty(); + } + + static void withDebugger(@Nonnull final Consumer action) { + getDebuggerMaybe().ifPresent(action); + } + + @Nonnull + static Optional mapDebugger(@Nonnull final Function function) { + return getDebuggerMaybe().map(function); + } + + @Nonnull + Optional getStatsMaps(); + + void onEvent(Debugger.Event event); +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsMaps.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsMaps.java index 3ccae3ad15..a8a86727d8 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsMaps.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsMaps.java @@ -21,29 +21,45 @@ package com.apple.foundationdb.record.query.plan.cascades.debug; import com.apple.foundationdb.record.query.plan.cascades.CascadesRule; +import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; import com.google.common.base.Suppliers; import com.google.common.collect.ImmutableMap; import javax.annotation.Nonnull; +import java.util.LinkedHashMap; import java.util.Map; +import java.util.Optional; import java.util.function.Supplier; public class StatsMaps { @Nonnull - private final Map, ? extends Stats> eventClassStatsMap; + private final Map, ? extends Stats> eventWithoutStateClassStatsMap; + @Nonnull + private final Map, ? extends Stats>> eventWithStateClassStatsByPlannerPhaseMap; @Nonnull private final Map>, ? extends Stats> plannerRuleClassStatsMap; @Nonnull private final Supplier, Stats>> immutableEventClassStatsMapSupplier; @Nonnull + private final Supplier, Stats>> immutableEventWithoutStateClassStatsMapSupplier; + @Nonnull + private final Supplier, Stats>>> immutableEventWithStateClassStatsByPlannerPhaseMapSupplier; + @Nonnull private final Supplier>, Stats>> immutablePlannerRuleClassStatsMapSupplier; - public StatsMaps(@Nonnull final Map, ? extends Stats> eventClassStatsMap, + + public StatsMaps(@Nonnull final Map, ? extends Stats> eventWithoutStateClassStatsMap, + @Nonnull final Map, ? extends Stats>> eventWithStateClassStatsByPlannerPhaseMap, @Nonnull final Map>, ? extends Stats> plannerRuleClassStatsMap) { - this.eventClassStatsMap = eventClassStatsMap; + + this.eventWithoutStateClassStatsMap = eventWithoutStateClassStatsMap; + this.eventWithStateClassStatsByPlannerPhaseMap = eventWithStateClassStatsByPlannerPhaseMap; this.plannerRuleClassStatsMap = plannerRuleClassStatsMap; + this.immutableEventClassStatsMapSupplier = Suppliers.memoize(this::computeImmutableEventClassStatsMap); + this.immutableEventWithoutStateClassStatsMapSupplier = Suppliers.memoize(this::computeImmutableEventWithoutStateClassStatsMap); + this.immutableEventWithStateClassStatsByPlannerPhaseMapSupplier = Suppliers.memoize(this::computeImmutableEventWithStateClassStatsByPlannerPhaseMap); this.immutablePlannerRuleClassStatsMapSupplier = Suppliers.memoize(this::computeImmutablePlannerRuleClassStatsMap); } @@ -58,13 +74,56 @@ public Map>, Stats> getPlannerRuleClassStatsMap( } @Nonnull - private Map, Stats> computeImmutableEventClassStatsMap() { - final var eventClassStatsMapBuilder = + public Map, Stats> getEventWithoutStateClassStatsMap() { + return immutableEventWithoutStateClassStatsMapSupplier.get(); + } + + @Nonnull + public Optional, Stats>> getEventWithStateClassStatsMapByPlannerPhase(@Nonnull PlannerPhase plannerPhase) { + return Optional.ofNullable(immutableEventWithStateClassStatsByPlannerPhaseMapSupplier.get().get(plannerPhase)); + } + + private Map, Stats> computeImmutableEventWithoutStateClassStatsMap() { + final var eventWithoutStateClassStatsMapBuilder = ImmutableMap., Stats>builder(); - for (final var entry : eventClassStatsMap.entrySet()) { - eventClassStatsMapBuilder.put(entry.getKey(), entry.getValue().toImmutable()); + + eventWithoutStateClassStatsMap.forEach( + (eventClass, stats) -> eventWithoutStateClassStatsMapBuilder.put(eventClass, stats.toImmutable()) + ); + + return eventWithoutStateClassStatsMapBuilder.build(); + } + + @Nonnull + private Map, Stats> computeImmutableEventClassStatsMap() { + // Add all events not tied to a specific planner phase first + Map, Stats> result = new LinkedHashMap<>(this.immutableEventWithoutStateClassStatsMapSupplier.get()); + + // Merge the stats all events tied to a specific planner phase with other events + for (final var eventWithStateClassStats : eventWithStateClassStatsByPlannerPhaseMap.values()) { + for (final var eventWithStateClassStatsEntry : eventWithStateClassStats.entrySet()) { + result.merge( + eventWithStateClassStatsEntry.getKey(), + eventWithStateClassStatsEntry.getValue().toImmutable(), + (s1, s2) -> Stats.merge(s1, s2).toImmutable()); + } + } + + return ImmutableMap.copyOf(result); + } + + @Nonnull + private Map, Stats>> computeImmutableEventWithStateClassStatsByPlannerPhaseMap() { + final var eventClassStatsByPlannerPhaseMapBuilder = + ImmutableMap., Stats>>builder(); + for (final var eventClassStatsByPlannerPhaseEntry : eventWithStateClassStatsByPlannerPhaseMap.entrySet()) { + final Map, Stats> eventClassImmutableStats = + eventClassStatsByPlannerPhaseEntry.getValue().entrySet().stream().collect( + ImmutableMap.toImmutableMap(Map.Entry::getKey, e -> e.getValue().toImmutable()) + ); + eventClassStatsByPlannerPhaseMapBuilder.put(eventClassStatsByPlannerPhaseEntry.getKey(), eventClassImmutableStats); } - return eventClassStatsMapBuilder.build(); + return eventClassStatsByPlannerPhaseMapBuilder.build(); } @Nonnull diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsViewer.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsViewer.java new file mode 100644 index 0000000000..b3d3d8a68b --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/StatsViewer.java @@ -0,0 +1,151 @@ +/* + * StatsViewer.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; +import com.apple.foundationdb.record.util.pair.Pair; +import com.google.common.collect.ImmutableMap; + +import javax.annotation.Nonnull; +import java.util.Locale; +import java.util.Map; +import java.util.Optional; +import java.util.concurrent.TimeUnit; + +/** + * A class that can be used to view {@link Stats} for all {@link Debugger.Event} collected by {@link StatsDebugger} + * during planning in a browser. + *

+ * To view the stats, evaluate the following expression in a debugging session at a breakpoint before the Cascades planner + * returns the plan: + * 

+ *     StatsViewer.showStats(StatsDebugger.getDebuggerMaybe().get())
+ *
+ * + * The stats will be displayed in a new window of the system browser. + *

+ */ +@SuppressWarnings("unused") +public class StatsViewer { + public static String showStats(@Nonnull final StatsDebugger statsDebugger) { + final var statsMaps = statsDebugger.getStatsMaps(); + + if (statsMaps.isEmpty()) { + return "no stats available"; + } + + StringBuilder tableBuilder = new StringBuilder(); + + final var phaseNameToStatsMap = ImmutableMap.of( + "Rewriting", statsMaps.get().getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.REWRITING), + "Planning", statsMaps.get().getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.PLANNING), + "Unspecified", Optional.of(statsMaps.get().getEventWithoutStateClassStatsMap()) + ); + + for (final var phaseNameToStatsMapEntry : phaseNameToStatsMap.entrySet()) { + if (phaseNameToStatsMapEntry.getValue().map(Map::isEmpty).orElse(false)) { + continue; + } + + tableBuilder.append("

").append(phaseNameToStatsMapEntry.getKey()).append(" Phase:

"); + tableBuilder.append(""); + tableHeader(tableBuilder, "Event"); + + final ImmutableMap eventStatsMap = + phaseNameToStatsMapEntry.getValue().get().entrySet() + .stream() + .map(entry -> Pair.of(entry.getKey().getSimpleName(), entry.getValue())) + .sorted(Map.Entry.comparingByKey()) + .collect(ImmutableMap.toImmutableMap(Pair::getKey, Pair::getValue)); + + tableBody(tableBuilder, eventStatsMap); + tableBuilder.append("
"); + } + + final String eventProfilingString = tableBuilder.toString(); + + tableBuilder = new StringBuilder(); + tableBuilder.append(""); + tableHeader(tableBuilder, "Planner Rule"); + final ImmutableMap plannerRuleStatsMap = + statsMaps.get().getPlannerRuleClassStatsMap().entrySet() + .stream() + .map(entry -> Pair.of(entry.getKey().getSimpleName(), entry.getValue())) + .sorted(Map.Entry.comparingByKey()) + .collect(ImmutableMap.toImmutableMap(Pair::getKey, Pair::getValue)); + tableBody(tableBuilder, plannerRuleStatsMap); + tableBuilder.append("
"); + + final String plannerRuleProfilingString = tableBuilder.toString(); + + return BrowserHelper.browse("/showProfilingReport.html", + ImmutableMap.of("$EVENT_PROFILING", eventProfilingString, + "$PLANNER_RULE_PROFILING", plannerRuleProfilingString)); + } + + private static void tableHeader(@Nonnull final StringBuilder stringBuilder, @Nonnull final String category) { + stringBuilder.append(""); + stringBuilder.append(""); + stringBuilder.append("").append(category).append(""); + stringBuilder.append("Location"); + stringBuilder.append("Count"); + stringBuilder.append("Total Time (micros)"); + stringBuilder.append("Average Time (micros)"); + stringBuilder.append("Total Own Time (micros)"); + stringBuilder.append("Average Own Time (micros)"); + stringBuilder.append(""); + stringBuilder.append(""); + } + + private static void tableBody(@Nonnull final StringBuilder stringBuilder, @Nonnull final Map statsMap) { + stringBuilder.append(""); + for (final Map.Entry entry : statsMap.entrySet()) { + final Stats stats = entry.getValue(); + for (final var locationEntry : stats.getLocationCountMap().entrySet()) { + stringBuilder.append(""); + stringBuilder.append("").append(entry.getKey()).append(""); + if (locationEntry.getKey() == Debugger.Location.BEGIN) { + stringBuilder.append(""); + } else { + stringBuilder.append("").append(locationEntry.getKey().name()).append(""); + } + stringBuilder.append("").append(locationEntry.getValue()).append(""); + if (locationEntry.getKey() == Debugger.Location.BEGIN) { + stringBuilder.append("").append(formatNsInMicros(stats.getTotalTimeInNs())).append(""); + stringBuilder.append("").append(formatNsInMicros(stats.getTotalTimeInNs() / stats.getCount(Debugger.Location.BEGIN))).append(""); + stringBuilder.append("").append(formatNsInMicros(stats.getOwnTimeInNs())).append(""); + stringBuilder.append("").append(formatNsInMicros(stats.getOwnTimeInNs() / stats.getCount(Debugger.Location.BEGIN))).append(""); + } else { + stringBuilder.append(""); + stringBuilder.append(""); + } + stringBuilder.append(""); + } + } + stringBuilder.append(""); + } + + @Nonnull + private static String formatNsInMicros(final long ns) { + final long micros = TimeUnit.NANOSECONDS.toMicros(ns); + return String.format(Locale.ROOT, "%,d", micros); + } +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolDebugger.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolDebugger.java new file mode 100644 index 0000000000..7392412e82 --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolDebugger.java @@ -0,0 +1,105 @@ +/* + * SymbolDebugger.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import com.apple.foundationdb.record.query.plan.cascades.Quantifier; +import com.apple.foundationdb.record.query.plan.cascades.Reference; +import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression; +import com.google.errorprone.annotations.CanIgnoreReturnValue; + +import javax.annotation.Nonnull; +import javax.annotation.Nullable; +import java.util.Optional; +import java.util.function.Consumer; +import java.util.function.Function; +import java.util.function.IntUnaryOperator; + +/** + *

+ * This interface extends the {@link Debugger} interface and provides functionality related to + * registering different symbols (i.e. objects) during planning and retrieving debugging-friendly + * names for them. + *

+ * Similar to the {@link Debugger} interface, the main mean of communication with the debugger + * for operations related to recording events is the set of statics defined within this interface. + *

+ */ +public interface SymbolDebugger extends Debugger { + @Nonnull + static Optional getDebuggerMaybe() { + final var debugger = Debugger.getDebugger(); + if (debugger instanceof SymbolDebugger) { + return Optional.of((SymbolDebugger)debugger); + } + return Optional.empty(); + } + + static void withDebugger(@Nonnull final Consumer action) { + getDebuggerMaybe().ifPresent(action); + } + + + @Nonnull + static Optional mapDebugger(@Nonnull final Function function) { + return getDebuggerMaybe().map(function); + } + + static Optional getIndexOptional(Class clazz) { + return mapDebugger(debugger -> debugger.onGetIndex(clazz)); + } + + @Nonnull + @CanIgnoreReturnValue + static Optional updateIndex(Class clazz, IntUnaryOperator updateFn) { + return mapDebugger(debugger -> debugger.onUpdateIndex(clazz, updateFn)); + } + + static void registerExpression(RelationalExpression expression) { + withDebugger(debugger -> debugger.onRegisterExpression(expression)); + } + + static void registerReference(Reference reference) { + withDebugger(debugger -> debugger.onRegisterReference(reference)); + } + + static void registerQuantifier(Quantifier quantifier) { + withDebugger(debugger -> debugger.onRegisterQuantifier(quantifier)); + } + + static Optional getOrRegisterSingleton(Object singleton) { + return mapDebugger(debugger -> debugger.onGetOrRegisterSingleton(singleton)); + } + + int onGetIndex(@Nonnull Class clazz); + + int onUpdateIndex(@Nonnull Class clazz, @Nonnull IntUnaryOperator updateFn); + + void onRegisterExpression(@Nonnull RelationalExpression expression); + + void onRegisterReference(@Nonnull Reference reference); + + void onRegisterQuantifier(@Nonnull Quantifier quantifier); + + int onGetOrRegisterSingleton(@Nonnull Object singleton); + + @Nullable + String nameForObject(@Nonnull Object object); +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolTables.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolTables.java new file mode 100644 index 0000000000..cdc8c63cac --- /dev/null +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/SymbolTables.java @@ -0,0 +1,174 @@ +/* + * SymbolState.java + * + * This source file is part of the FoundationDB open source project + * + * Copyright 2015-2025 Apple Inc. and the FoundationDB project authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.apple.foundationdb.record.query.plan.cascades.debug; + +import com.apple.foundationdb.record.query.plan.cascades.Quantifier; +import com.apple.foundationdb.record.query.plan.cascades.Reference; +import com.apple.foundationdb.record.query.plan.cascades.expressions.RelationalExpression; +import com.google.common.cache.Cache; +import com.google.common.cache.CacheBuilder; +import com.google.common.collect.Maps; +import com.google.errorprone.annotations.CanIgnoreReturnValue; + + + +import javax.annotation.Nonnull; +import java.util.Map; +import java.util.function.IntUnaryOperator; + +/** + * A class used by different implementations of {@link SymbolDebugger} to map different types of objects + * during planning ({@link RelationalExpression}, {@link Reference}, {@link Quantifier}) to unique indices, which + * is used to generate debugging-friendly names for these objects. + */ +public class SymbolTables { + @Nonnull + private final Map, Integer> classToIndexMap; + @Nonnull + private final Cache expressionCache; + @Nonnull private final Cache invertedExpressionsCache; + @Nonnull private final Cache referenceCache; + @Nonnull private final Cache invertedReferenceCache; + @Nonnull private final Cache quantifierCache; + @Nonnull private final Cache invertedQuantifierCache; + + public static SymbolTables copyOf(final SymbolTables source) { + final Cache copyExpressionCache = CacheBuilder.newBuilder().weakValues().build(); + source.getExpressionCache().asMap().forEach(copyExpressionCache::put); + final Cache copyInvertedExpressionsCache = CacheBuilder.newBuilder().weakKeys().build(); + source.getInvertedExpressionsCache().asMap().forEach(copyInvertedExpressionsCache::put); + final Cache copyReferenceCache = CacheBuilder.newBuilder().weakValues().build(); + source.getReferenceCache().asMap().forEach(copyReferenceCache::put); + final Cache copyInvertedReferenceCache = CacheBuilder.newBuilder().weakKeys().build(); + source.getInvertedReferenceCache().asMap().forEach(copyInvertedReferenceCache::put); + final Cache copyQuantifierCache = CacheBuilder.newBuilder().weakValues().build(); + source.getQuantifierCache().asMap().forEach(copyQuantifierCache::put); + final Cache copyInvertedQuantifierCache = CacheBuilder.newBuilder().weakKeys().build(); + source.getInvertedQuantifierCache().asMap().forEach(copyInvertedQuantifierCache::put); + + return new SymbolTables(source.getClassToIndexMap(), + copyExpressionCache, + copyInvertedExpressionsCache, + copyReferenceCache, + copyInvertedReferenceCache, + copyQuantifierCache, + copyInvertedQuantifierCache); + } + + public SymbolTables() { + classToIndexMap = Maps.newHashMap(); + expressionCache = CacheBuilder.newBuilder().weakValues().build(); + invertedExpressionsCache = CacheBuilder.newBuilder().weakKeys().build(); + referenceCache = CacheBuilder.newBuilder().weakValues().build(); + invertedReferenceCache = CacheBuilder.newBuilder().weakKeys().build(); + quantifierCache = CacheBuilder.newBuilder().weakValues().build(); + invertedQuantifierCache = CacheBuilder.newBuilder().weakKeys().build(); + } + + private SymbolTables(@Nonnull final Map, Integer> classToIndexMap, + @Nonnull final Cache expressionCache, + @Nonnull final Cache invertedExpressionsCache, + @Nonnull final Cache referenceCache, + @Nonnull final Cache invertedReferenceCache, + @Nonnull final Cache quantifierCache, + @Nonnull final Cache invertedQuantifierCache) { + this.classToIndexMap = Maps.newHashMap(classToIndexMap); + this.expressionCache = expressionCache; + this.invertedExpressionsCache = invertedExpressionsCache; + this.referenceCache = referenceCache; + this.invertedReferenceCache = invertedReferenceCache; + this.quantifierCache = quantifierCache; + this.invertedQuantifierCache = invertedQuantifierCache; + } + + @Nonnull + private Map, Integer> getClassToIndexMap() { + return classToIndexMap; + } + + @Nonnull + public Cache getExpressionCache() { + return expressionCache; + } + + @Nonnull + public Cache getInvertedExpressionsCache() { + return invertedExpressionsCache; + } + + @Nonnull + public Cache getReferenceCache() { + return referenceCache; + } + + @Nonnull + public Cache getInvertedReferenceCache() { + return invertedReferenceCache; + } + + @Nonnull + public Cache getQuantifierCache() { + return quantifierCache; + } + + @Nonnull + public Cache getInvertedQuantifierCache() { + return invertedQuantifierCache; + } + + + public int getIndex(final Class clazz) { + return classToIndexMap.getOrDefault(clazz, 0); + } + + @CanIgnoreReturnValue + public int updateIndex(final Class clazz, IntUnaryOperator computeFn) { + return classToIndexMap.compute(clazz, (c, value) -> value == null ? computeFn.applyAsInt(0) : computeFn.applyAsInt(value)); + } + + public void registerExpression(final RelationalExpression expression) { + if (invertedExpressionsCache.getIfPresent(expression) == null) { + final int index = getIndex(RelationalExpression.class); + expressionCache.put(index, expression); + invertedExpressionsCache.put(expression, index); + updateIndex(RelationalExpression.class, i -> i + 1); + } + } + + public void registerReference(final Reference reference) { + if (invertedReferenceCache.getIfPresent(reference) == null) { + final int index = getIndex(Reference.class); + referenceCache.put(index, reference); + invertedReferenceCache.put(reference, index); + updateIndex(Reference.class, i -> i + 1); + } + } + + public void registerQuantifier(final Quantifier quantifier) { + if (invertedQuantifierCache.getIfPresent(quantifier) == null) { + final int index = getIndex(Quantifier.class); + quantifierCache.put(index, quantifier); + invertedQuantifierCache.put(quantifier, index); + updateIndex(Quantifier.class, i -> i + 1); + } + } + +} diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/explain/PlannerGraphVisitor.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/explain/PlannerGraphVisitor.java index 721fb3e424..df71082516 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/explain/PlannerGraphVisitor.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/explain/PlannerGraphVisitor.java @@ -26,7 +26,7 @@ import com.apple.foundationdb.record.query.plan.cascades.SimpleExpressionVisitor; import com.apple.foundationdb.record.query.plan.cascades.Traversal; import com.apple.foundationdb.record.query.plan.cascades.debug.BrowserHelper; -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.explain.GraphExporter.Cluster; import com.apple.foundationdb.record.query.plan.cascades.explain.GraphExporter.ComponentIdProvider; import com.apple.foundationdb.record.query.plan.cascades.explain.PlannerGraph.Edge; @@ -323,7 +323,7 @@ private static Collection> clustersForGroups(final Network { - final String label = Debugger.mapDebugger(debugger -> debugger.nameForObject(entry.getKey().getIdentity())) + final String label = SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(entry.getKey().getIdentity())) .orElse("group"); return new GroupCluster(label, entry.getValue()); }) @@ -509,7 +509,7 @@ public PlannerGraph evaluateAtRef(@Nonnull final Reference ref, @Nonnull List { final Node root = childGraph.getRoot(); final Optional debugNameOptional = - Debugger.mapDebugger(debugger -> { + SymbolDebugger.mapDebugger(debugger -> { if (root instanceof PlannerGraph.WithExpression) { final PlannerGraph.WithExpression withExpression = (PlannerGraph.WithExpression)root; @Nullable final RelationalExpression expression = withExpression.getExpression(); diff --git a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/rules/ImplementNestedLoopJoinRule.java b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/rules/ImplementNestedLoopJoinRule.java index 7d1e65a68e..053dcb621f 100644 --- a/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/rules/ImplementNestedLoopJoinRule.java +++ b/fdb-record-layer-core/src/main/java/com/apple/foundationdb/record/query/plan/cascades/rules/ImplementNestedLoopJoinRule.java @@ -29,6 +29,7 @@ import com.apple.foundationdb.record.query.plan.cascades.Reference; import com.apple.foundationdb.record.query.plan.cascades.RequestedOrderingConstraint; 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.SelectExpression; import com.apple.foundationdb.record.query.plan.cascades.matching.structure.BindingMatcher; import com.apple.foundationdb.record.query.plan.cascades.predicates.QueryPredicate; @@ -111,7 +112,7 @@ public void onMatch(@Nonnull final ImplementationCascadesRuleCall call) { final var outerPartition = bindings.get(outerPlanPartitionsMatcher); final var innerPartition = bindings.get(innerPlanPartitionsMatcher); - final var joinName = Debugger.mapDebugger(debugger -> debugger.nameForObject(call.getRoot()) + "[" + debugger.nameForObject(selectExpression) + "]: " + outerQuantifier.getAlias() + " ⨝ " + innerQuantifier.getAlias()).orElse("not in debug mode"); + final var joinName = SymbolDebugger.mapDebugger(debugger -> debugger.nameForObject(call.getRoot()) + "[" + debugger.nameForObject(selectExpression) + "]: " + outerQuantifier.getAlias() + " ⨝ " + innerQuantifier.getAlias()).orElse("not in debug mode"); Debugger.withDebugger(debugger -> logger.debug(KeyValueLogMessage.of("attempting join", "joinedTables", joinName, "requestedOrderings", requestedOrderings))); final var fullCorrelationOrder = diff --git a/fdb-record-layer-core/src/test/java/com/apple/foundationdb/record/provider/foundationdb/query/FDBRecordStoreQueryTestBase.java b/fdb-record-layer-core/src/test/java/com/apple/foundationdb/record/provider/foundationdb/query/FDBRecordStoreQueryTestBase.java index 60dc3336c3..16b8efe8c5 100644 --- a/fdb-record-layer-core/src/test/java/com/apple/foundationdb/record/provider/foundationdb/query/FDBRecordStoreQueryTestBase.java +++ b/fdb-record-layer-core/src/test/java/com/apple/foundationdb/record/provider/foundationdb/query/FDBRecordStoreQueryTestBase.java @@ -57,6 +57,7 @@ import com.apple.foundationdb.record.query.plan.RecordQueryPlanner; import com.apple.foundationdb.record.query.plan.cascades.CascadesPlanner; import com.apple.foundationdb.record.query.plan.cascades.CorrelationIdentifier; +import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; import com.apple.foundationdb.record.query.plan.cascades.Reference; import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger; import com.apple.foundationdb.record.query.plan.cascades.matching.structure.BindingMatcher; @@ -101,6 +102,7 @@ import static org.hamcrest.Matchers.greaterThanOrEqualTo; import static org.hamcrest.Matchers.instanceOf; import static org.hamcrest.Matchers.lessThanOrEqualTo; +import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertTrue; import static org.junit.jupiter.api.Assertions.fail; @@ -664,7 +666,24 @@ protected RecordQueryPlan planGraph(@Nonnull Supplier querySupplier, assertNotNull(statsMaps); final var eventClassStatsMap = statsMaps.getEventClassStatsMap(); assertTrue(eventClassStatsMap.containsKey(Debugger.ExecutingTaskEvent.class)); - assertTrue(eventClassStatsMap.get(Debugger.ExecutingTaskEvent.class).getCount(Debugger.Location.BEGIN) > 0); + + final var eventClassStatsMapForRewriting = statsMaps.getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.REWRITING); + assertTrue(eventClassStatsMapForRewriting.isPresent()); + assertTrue(eventClassStatsMapForRewriting.get().containsKey(Debugger.ExecutingTaskEvent.class)); + assertTrue(eventClassStatsMapForRewriting.get().get(Debugger.ExecutingTaskEvent.class).getCount(Debugger.Location.BEGIN) > 0); + + final var eventClassStatsMapForPlanning = statsMaps.getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.PLANNING); + assertTrue(eventClassStatsMapForPlanning.isPresent()); + assertTrue(eventClassStatsMapForPlanning.get().containsKey(Debugger.ExecutingTaskEvent.class)); + + final var totalTasks = eventClassStatsMap.get(Debugger.ExecutingTaskEvent.class).getCount(Debugger.Location.BEGIN); + final var rewritingTasks = eventClassStatsMapForRewriting.get().get(Debugger.ExecutingTaskEvent.class).getCount(Debugger.Location.BEGIN); + final var planningTasks = eventClassStatsMapForPlanning.get().get(Debugger.ExecutingTaskEvent.class).getCount(Debugger.Location.BEGIN); + + assertTrue(totalTasks > 0); + assertTrue(rewritingTasks > 0); + assertTrue(planningTasks > 0); + assertEquals(rewritingTasks + planningTasks, totalTasks); final var plan = planResult.getPlan(); System.out.println("\n" + ExplainPlanVisitor.prettyExplain(plan) + "\n"); @@ -693,7 +712,7 @@ protected static RecordQueryPlan verifySerialization(@Nonnull final RecordQueryP final PlanSerializationContext deserializationContext = new PlanSerializationContext(new DefaultPlanSerializationRegistry(), PlanHashable.CURRENT_FOR_CONTINUATION); final RecordQueryPlan deserializedPlan = RecordQueryPlan.fromRecordQueryPlanProto(deserializationContext, parsedPlanProto); - Assertions.assertEquals(plan.planHash(PlanHashable.CURRENT_FOR_CONTINUATION), deserializedPlan.planHash(PlanHashable.CURRENT_FOR_CONTINUATION)); + assertEquals(plan.planHash(PlanHashable.CURRENT_FOR_CONTINUATION), deserializedPlan.planHash(PlanHashable.CURRENT_FOR_CONTINUATION)); Assertions.assertTrue(plan.structuralEquals(deserializedPlan)); return deserializedPlan; } diff --git a/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Commands.java b/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Commands.java index 128eb8f900..5abe3864da 100644 --- a/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Commands.java +++ b/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/Commands.java @@ -309,13 +309,13 @@ public static class CurrentCommand implements Command { public boolean executeCommand(@Nonnull final PlannerRepl plannerRepl, @Nonnull final Event event, @Nonnull final ParsedLine parsedLine) { - final State state = plannerRepl.getCurrentState(); - final List events = state.getEvents(); + final EventState eventState = plannerRepl.getCurrentState(); + final List events = eventState.getEvents(); if (events == null) { plannerRepl.printlnError("Configuration mandates to not record events. Please turn on event recording and restart."); return false; } - final Event e = events.get(state.getCurrentTick()); + final Event e = events.get(eventState.getCurrentTick()); plannerRepl.withProcessors(e, processor -> processor.onDetail(plannerRepl, e)); return false; } @@ -341,15 +341,15 @@ public static class EventsCommand implements Command { public boolean executeCommand(@Nonnull final PlannerRepl plannerRepl, @Nonnull final Event event, @Nonnull final ParsedLine parsedLine) { - final State state = plannerRepl.getCurrentState(); - final List events = state.getEvents(); + final EventState eventState = plannerRepl.getCurrentState(); + final List events = eventState.getEvents(); if (events == null) { plannerRepl.printlnError("Configuration mandates to not record events. Please turn on event recording and restart."); return false; } for (int tick = 0; tick < events.size(); tick++) { final Event e = events.get(tick); - if (state.getCurrentTick() == tick) { + if (eventState.getCurrentTick() == tick) { plannerRepl.printHighlighted("==> "); } else { plannerRepl.print(" "); @@ -382,7 +382,7 @@ public static class ExpsCommand implements Command { public boolean executeCommand(@Nonnull final PlannerRepl plannerRepl, @Nonnull final Event event, @Nonnull final ParsedLine parsedLine) { - final State state = plannerRepl.getCurrentState(); + final SymbolTables state = plannerRepl.getCurrentSymbolState(); final Cache expressionCache = state.getExpressionCache(); final List ids = Lists.newArrayList(expressionCache.asMap().keySet()); Collections.sort(ids); @@ -452,7 +452,7 @@ public static class RefsCommand implements Command { public boolean executeCommand(@Nonnull final PlannerRepl plannerRepl, @Nonnull final Event event, @Nonnull final ParsedLine parsedLine) { - final State state = plannerRepl.getCurrentState(); + final SymbolTables state = plannerRepl.getCurrentSymbolState(); final Cache referenceCache = state.getReferenceCache(); final List ids = Lists.newArrayList(referenceCache.asMap().keySet()); Collections.sort(ids); @@ -724,7 +724,7 @@ public static class QunsCommand implements Command { public boolean executeCommand(@Nonnull final PlannerRepl plannerRepl, @Nonnull final Event event, @Nonnull final ParsedLine parsedLine) { - final State state = plannerRepl.getCurrentState(); + final SymbolTables state = plannerRepl.getCurrentSymbolState(); final List ids = Lists.newArrayList(state.getQuantifierCache().asMap().keySet()); Collections.sort(ids); for (Integer id : ids) { diff --git a/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/PlannerRepl.java b/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/PlannerRepl.java index 2d52da7453..6df35a0fb7 100644 --- a/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/PlannerRepl.java +++ b/fdb-record-layer-debugger/src/main/java/com/apple/foundationdb/record/query/plan/cascades/debug/PlannerRepl.java @@ -69,7 +69,7 @@ /** * Implementation of a debugger as a repl. */ -public class PlannerRepl implements Debugger { +public class PlannerRepl implements StatsDebugger, SymbolDebugger { private static final Logger logger = LoggerFactory.getLogger(PlannerRepl.class); private static final String banner = @@ -92,7 +92,8 @@ public class PlannerRepl implements Debugger { processorsMap = loadProcessors(); } - private final Deque stateStack; + private final Deque eventStateStack; + private final Deque symbolTablesStack; private final BiMap breakPoints; private int currentBreakPointIndex; @@ -117,7 +118,8 @@ public PlannerRepl(@Nonnull final Terminal terminal) { } public PlannerRepl(@Nonnull final Terminal terminal, boolean exitOnQuit) { - this.stateStack = new ArrayDeque<>(); + this.eventStateStack = new ArrayDeque<>(); + this.symbolTablesStack = new ArrayDeque<>(); this.breakPoints = HashBiMap.create(); this.currentBreakPointIndex = 0; this.currentInternalBreakPointIndex = -1; @@ -133,10 +135,15 @@ boolean shouldExitOnQuit() { } @Nonnull - State getCurrentState() { - return Objects.requireNonNull(stateStack.peek()); + SymbolTables getCurrentSymbolState() { + return Objects.requireNonNull(symbolTablesStack.peek()); } + EventState getCurrentState() { + return Objects.requireNonNull(eventStateStack.peek()); + } + + @Nullable @Override public PlanContext getPlanContext() { @@ -151,27 +158,27 @@ public boolean isSane() { @Override public int onGetIndex(@Nonnull final Class clazz) { - return getCurrentState().getIndex(clazz); + return getCurrentSymbolState().getIndex(clazz); } @Override public int onUpdateIndex(@Nonnull final Class clazz, @Nonnull final IntUnaryOperator updateFn) { - return getCurrentState().updateIndex(clazz, updateFn); + return getCurrentSymbolState().updateIndex(clazz, updateFn); } @Override public void onRegisterExpression(@Nonnull final RelationalExpression expression) { - getCurrentState().registerExpression(expression); + getCurrentSymbolState().registerExpression(expression); } @Override public void onRegisterReference(@Nonnull final Reference reference) { - getCurrentState().registerReference(reference); + getCurrentSymbolState().registerReference(reference); } @Override public void onRegisterQuantifier(@Nonnull final Quantifier quantifier) { - getCurrentState().registerQuantifier(quantifier); + getCurrentSymbolState().registerQuantifier(quantifier); } @Override @@ -203,7 +210,9 @@ public void onShow(@Nonnull final Reference ref) { @Override public void onQuery(@Nonnull final String queryAsString, @Nonnull final PlanContext planContext) { - this.stateStack.push(State.copyOf(getCurrentState())); + this.eventStateStack.push(EventState.copyOf(getCurrentState())); + this.symbolTablesStack.push(SymbolTables.copyOf(getCurrentSymbolState())); + this.queryAsString = queryAsString; this.planContext = planContext; @@ -214,8 +223,11 @@ public void onQuery(@Nonnull final String queryAsString, @Nonnull final PlanCont } void restartState() { - stateStack.pop(); - stateStack.push(State.copyOf(getCurrentState())); + eventStateStack.pop(); + eventStateStack.push(EventState.copyOf(getCurrentState())); + + symbolTablesStack.pop(); + symbolTablesStack.push(SymbolTables.copyOf(getCurrentSymbolState())); } void addBreakPoint(final BreakPoint breakPoint) { @@ -255,9 +267,9 @@ public void onEvent(final Event event) { Objects.requireNonNull(queryAsString); Objects.requireNonNull(planContext); - final State state = getCurrentState(); + final EventState eventState = getCurrentState(); - state.addCurrentEvent(event); + eventState.addCurrentEvent(event); final Set satisfiedBreakPoints = computeSatisfiedBreakPoints(event); satisfiedBreakPoints.forEach(breakPoint -> breakPoint.onBreak(this)); @@ -265,7 +277,7 @@ public void onEvent(final Event event) { final boolean stop = !satisfiedBreakPoints.isEmpty(); if (stop) { printKeyValue("paused in", Thread.currentThread().getName() + " at "); - printlnKeyValue("tick", String.valueOf(state.getCurrentTick())); + printlnKeyValue("tick", String.valueOf(eventState.getCurrentTick())); withProcessors(event, processor -> processor.onCallback(this, event)); println(); @@ -332,7 +344,7 @@ boolean processIdentifiers(final String potentialIdentifier, final Consumer expressionConsumer, final Consumer referenceConsumer, final Consumer quantifierConsumer) { - final State state = getCurrentState(); + final SymbolTables state = getCurrentSymbolState(); final String upperCasePotentialIdentifier = potentialIdentifier.toUpperCase(Locale.ROOT); if (upperCasePotentialIdentifier.startsWith("EXP")) { @Nullable final RelationalExpression expression = lookupInCache(state.getExpressionCache(), upperCasePotentialIdentifier, "EXP"); @@ -399,7 +411,7 @@ boolean isValidEntityName(@Nonnull final String identifier) { @Nullable @Override public String nameForObject(@Nonnull final Object object) { - final State state = getCurrentState(); + final SymbolTables state = getCurrentSymbolState(); if (object instanceof RelationalExpression) { @Nullable final Integer id = state.getInvertedExpressionsCache().getIfPresent(object); return (id == null) ? null : "exp" + id; @@ -453,28 +465,21 @@ public void onDone() { reset(); } - @Override - public String showStats() { - State currentState = stateStack.peek(); - if (currentState != null) { - return currentState.showStats(); - } - return "no stats"; - } - @Nonnull @Override public Optional getStatsMaps() { - State currentState = stateStack.peek(); - if (currentState != null) { - return Optional.of(currentState.getStatsMaps()); + EventState currentEventState = eventStateStack.peek(); + if (currentEventState != null) { + return Optional.of(currentEventState.getStatsMaps()); } return Optional.empty(); } private void reset() { - this.stateStack.clear(); - this.stateStack.push(State.initial(true, true, null)); + this.eventStateStack.clear(); + this.eventStateStack.push(EventState.initial(true, true, null)); + this.symbolTablesStack.clear(); + this.symbolTablesStack.push(new SymbolTables()); this.breakPoints.clear(); this.currentBreakPointIndex = 0; this.currentInternalBreakPointIndex = -1; diff --git a/fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/QueryPlan.java b/fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/QueryPlan.java index 47ea0ffa34..a31cb6b380 100644 --- a/fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/QueryPlan.java +++ b/fdb-relational-core/src/main/java/com/apple/foundationdb/relational/recordlayer/query/QueryPlan.java @@ -33,6 +33,7 @@ import com.apple.foundationdb.record.query.plan.QueryPlanInfoKeys; import com.apple.foundationdb.record.query.plan.QueryPlanResult; import com.apple.foundationdb.record.query.plan.cascades.CascadesPlanner; +import com.apple.foundationdb.record.query.plan.cascades.PlannerPhase; import com.apple.foundationdb.record.query.plan.cascades.Reference; import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger; import com.apple.foundationdb.record.query.plan.cascades.debug.Stats; @@ -88,6 +89,7 @@ import java.sql.Struct; import java.util.ArrayList; import java.util.Collections; + import java.util.List; import java.util.Map; import java.util.Objects; @@ -296,7 +298,11 @@ private RelationalResultSet executeExplain(@Nonnull ContinuationImpl parsedConti DataType.StructType.Field.from("TRANSFORM_YIELD_COUNT", DataType.Primitives.LONG.type(), 4), DataType.StructType.Field.from("INSERT_TIME_NS", DataType.Primitives.LONG.type(), 5), DataType.StructType.Field.from("INSERT_NEW_COUNT", DataType.Primitives.LONG.type(), 6), - DataType.StructType.Field.from("INSERT_REUSED_COUNT", DataType.Primitives.LONG.type(), 7)), + DataType.StructType.Field.from("INSERT_REUSED_COUNT", DataType.Primitives.LONG.type(), 7), + DataType.StructType.Field.from("REWRITING_PHASE_TASK_COUNT", DataType.Primitives.LONG.type(), 8), + DataType.StructType.Field.from("PLANNING_PHASE_TASK_COUNT", DataType.Primitives.LONG.type(), 9), + DataType.StructType.Field.from("REWRITING_PHASE_TASKS_TOTAL_TIME_NS", DataType.Primitives.LONG.type(), 10), + DataType.StructType.Field.from("PLANNING_PHASE_TASKS_TOTAL_TIME_NS", DataType.Primitives.LONG.type(), 11)), true); final var explainStructType = DataType.StructType.from( "EXPLAIN", List.of( @@ -320,25 +326,35 @@ private RelationalResultSet executeExplain(@Nonnull ContinuationImpl parsedConti plannerMetrics = null; } else { final var plannerEventClassStatsMap = plannerStatsMaps.getEventClassStatsMap(); - final var executingTasksStats = + + final var aggregateExecutingTasksStats = Optional.ofNullable(plannerEventClassStatsMap.get(Debugger.ExecutingTaskEvent.class)); - final var transformRuleCallStats = + final var aggregateTransformRuleCallStats = Optional.ofNullable(plannerEventClassStatsMap.get(Debugger.TransformRuleCallEvent.class)); - final var insertIntoMemoStats = + final var aggregateInsertIntoMemoStats = Optional.ofNullable(plannerEventClassStatsMap.get(Debugger.InsertIntoMemoEvent.class)); + final var executingTasksStatsForRewritingPhase = + plannerStatsMaps.getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.REWRITING) + .map(m -> m.get(Debugger.ExecutingTaskEvent.class)); + final var executingTasksStatsForPlanningPhase = + plannerStatsMaps.getEventWithStateClassStatsMapByPlannerPhase(PlannerPhase.PLANNING) + .map(m -> m.get(Debugger.ExecutingTaskEvent.class)); + plannerMetrics = new ImmutableRowStruct(new ArrayRow( - executingTasksStats.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), - executingTasksStats.map(Stats::getTotalTimeInNs).orElse(0L), - transformRuleCallStats.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), - transformRuleCallStats.map(Stats::getOwnTimeInNs).orElse(0L), - transformRuleCallStats.map(s -> s.getCount(Debugger.Location.YIELD)).orElse(0L), - insertIntoMemoStats.map(Stats::getOwnTimeInNs).orElse(0L), - insertIntoMemoStats.map(s -> s.getCount(Debugger.Location.NEW)).orElse(0L), - insertIntoMemoStats.map(s -> s.getCount(Debugger.Location.REUSED)).orElse(0L), - parsedContinuation.getVersion(), - parsedContinuation.getCompiledStatement() == null ? null : parsedContinuation.getCompiledStatement().getPlanSerializationMode() + aggregateExecutingTasksStats.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), + aggregateExecutingTasksStats.map(Stats::getTotalTimeInNs).orElse(0L), + aggregateTransformRuleCallStats.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), + aggregateTransformRuleCallStats.map(Stats::getOwnTimeInNs).orElse(0L), + aggregateTransformRuleCallStats.map(s -> s.getCount(Debugger.Location.YIELD)).orElse(0L), + aggregateInsertIntoMemoStats.map(Stats::getOwnTimeInNs).orElse(0L), + aggregateInsertIntoMemoStats.map(s -> s.getCount(Debugger.Location.NEW)).orElse(0L), + aggregateInsertIntoMemoStats.map(s -> s.getCount(Debugger.Location.REUSED)).orElse(0L), + executingTasksStatsForRewritingPhase.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), + executingTasksStatsForPlanningPhase.map(s -> s.getCount(Debugger.Location.BEGIN)).orElse(0L), + executingTasksStatsForRewritingPhase.map(Stats::getTotalTimeInNs).orElse(0L), + executingTasksStatsForPlanningPhase.map(Stats::getTotalTimeInNs).orElse(0L) ), RelationalStructMetaData.of(plannerMetricsStructType)); } diff --git a/fdb-relational-core/src/test/java/com/apple/foundationdb/relational/recordlayer/query/ExplainTests.java b/fdb-relational-core/src/test/java/com/apple/foundationdb/relational/recordlayer/query/ExplainTests.java index ad1e844c62..bd9b582c97 100644 --- a/fdb-relational-core/src/test/java/com/apple/foundationdb/relational/recordlayer/query/ExplainTests.java +++ b/fdb-relational-core/src/test/java/com/apple/foundationdb/relational/recordlayer/query/ExplainTests.java @@ -40,6 +40,7 @@ import java.net.URI; import java.sql.SQLException; import java.sql.Types; +import java.util.Collections; import java.util.List; public class ExplainTests { @@ -71,6 +72,21 @@ void explainResultSetMetadataTest() throws Exception { final var expectedTypes = List.of(Types.VARCHAR, Types.INTEGER, Types.VARCHAR, Types.VARCHAR, Types.STRUCT, Types.STRUCT); final var expectedContLabels = List.of("EXECUTION_STATE", "VERSION", "PLAN_HASH_MODE"); final var expectedContTypes = List.of(Types.BINARY, Types.INTEGER, Types.VARCHAR); + final var expectedPlannerMetricsLabels = List.of( + "TASK_COUNT", + "TASK_TOTAL_TIME_NS", + "TRANSFORM_COUNT", + "TRANSFORM_TIME_NS", + "TRANSFORM_YIELD_COUNT", + "INSERT_TIME_NS", + "INSERT_NEW_COUNT", + "INSERT_REUSED_COUNT", + "REWRITING_PHASE_TASK_COUNT", + "PLANNING_PHASE_TASK_COUNT", + "REWRITING_PHASE_TASKS_TOTAL_TIME_NS", + "PLANNING_PHASE_TASKS_TOTAL_TIME_NS" + ); + final var expectedPlannerMetricsTypes = Collections.nCopies(expectedPlannerMetricsLabels.size(), Types.BIGINT); try (var ddl = Ddl.builder().database(URI.create("/TEST/QT")).relationalExtension(relationalExtension).schemaTemplate(schemaTemplate).build()) { executeInsert(ddl); try (RelationalPreparedStatement ps = ddl.setSchemaAndGetConnection().prepareStatement("EXPLAIN SELECT * FROM RestaurantComplexRecord")) { @@ -87,7 +103,12 @@ void explainResultSetMetadataTest() throws Exception { org.junit.jupiter.api.Assertions.assertEquals(expectedContLabels.get(i), actualContinuationMetadata.getColumnLabel(i + 1)); org.junit.jupiter.api.Assertions.assertEquals(expectedContTypes.get(i), actualContinuationMetadata.getColumnType(i + 1)); } - + final var actualPlannerMetricsMetadata = actualMetadata.getStructMetaData(6); + org.junit.jupiter.api.Assertions.assertEquals(expectedPlannerMetricsLabels.size(), actualPlannerMetricsMetadata.getColumnCount()); + for (int i = 0; i < expectedPlannerMetricsLabels.size(); i++) { + org.junit.jupiter.api.Assertions.assertEquals(expectedPlannerMetricsLabels.get(i), actualPlannerMetricsMetadata.getColumnLabel(i + 1)); + org.junit.jupiter.api.Assertions.assertEquals(expectedPlannerMetricsTypes.get(i), actualPlannerMetricsMetadata.getColumnType(i + 1)); + } } } } diff --git a/yaml-tests/src/main/java/com/apple/foundationdb/relational/yamltests/command/DebuggerImplementation.java b/yaml-tests/src/main/java/com/apple/foundationdb/relational/yamltests/command/DebuggerImplementation.java index f0c3334bce..918e8738fb 100644 --- a/yaml-tests/src/main/java/com/apple/foundationdb/relational/yamltests/command/DebuggerImplementation.java +++ b/yaml-tests/src/main/java/com/apple/foundationdb/relational/yamltests/command/DebuggerImplementation.java @@ -22,6 +22,7 @@ import com.apple.foundationdb.record.query.plan.cascades.debug.Debugger; import com.apple.foundationdb.record.query.plan.cascades.debug.DebuggerWithSymbolTables; +import com.apple.foundationdb.record.query.plan.cascades.debug.LightweightDebugger; import com.apple.foundationdb.record.query.plan.cascades.debug.PlannerRepl; import com.apple.foundationdb.relational.yamltests.YamlExecutionContext; import org.jline.terminal.TerminalBuilder; @@ -31,6 +32,7 @@ import java.util.function.Function; public enum DebuggerImplementation { + LIGHTWEIGHT(context -> new LightweightDebugger()), INSANE(context -> DebuggerWithSymbolTables.withSanityChecks()), SANE(context -> DebuggerWithSymbolTables.withoutSanityChecks()), REPL(context -> { diff --git a/yaml-tests/src/test/java/YamlIntegrationTests.java b/yaml-tests/src/test/java/YamlIntegrationTests.java index 138f9bcc75..c3ebec745c 100644 --- a/yaml-tests/src/test/java/YamlIntegrationTests.java +++ b/yaml-tests/src/test/java/YamlIntegrationTests.java @@ -305,4 +305,9 @@ public void literalExtractionTests(YamlTest.Runner runner) throws Exception { public void caseSensitivityTest(YamlTest.Runner runner) throws Exception { runner.runYamsql("case-sensitivity.yamsql"); } + + @TestTemplate + public void simpleQueryWithDifferentDebuggersTest(YamlTest.Runner runner) throws Exception { + runner.runYamsql("simple-query-with-different-debuggers.yamsql"); + } } diff --git a/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.binpb b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.binpb new file mode 100644 index 0000000000..ac0ef454d7 --- /dev/null +++ b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.binpb @@ -0,0 +1,14 @@ + +N +%simple-query-with-different-debuggers%EXPLAIN select * from t1 where id > 1 +"* (0I8@9SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG) +digraph G { + fontname=courier; + rankdir=BT; + splines=polyline; + 1 [ label=<
Predicate Filter
WHERE q9bd5c851_f08a_4d97_bc5d_1ae41728b1b7.ID GREATER_THAN promote(@c8 AS LONG)
> color="black" shape="plain" style="solid" fillcolor="black" fontname="courier" fontsize="8" tooltip="RELATION(LONG AS ID, )" ]; + 2 [ label=<
Scan
range: <-∞, ∞>
> color="black" shape="plain" style="solid" fillcolor="black" fontname="courier" fontsize="8" tooltip="RELATION(LONG AS ID, )" ]; + 3 [ label=<
Primary Storage
record types: [T1]
> color="black" shape="plain" style="filled" fillcolor="lightblue" fontname="courier" fontsize="8" tooltip="RELATION(LONG AS ID, )" ]; + 3 -> 2 [ color="gray20" style="solid" fontname="courier" fontsize="8" arrowhead="normal" arrowtail="none" dir="both" ]; + 2 -> 1 [ label=< q9bd5c851_f08a_4d97_bc5d_1ae41728b1b7> label="q9bd5c851_f08a_4d97_bc5d_1ae41728b1b7" color="gray20" style="bold" fontname="courier" fontsize="8" arrowhead="normal" arrowtail="none" dir="both" ]; +} \ No newline at end of file diff --git a/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.yaml b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.yaml new file mode 100644 index 0000000000..deaa3ecd54 --- /dev/null +++ b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.metrics.yaml @@ -0,0 +1,31 @@ +simple-query-with-different-debuggers: +- query: EXPLAIN select * from t1 where id > 1 + explain: SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG) + task_count: 163 + task_total_time_ms: 72 + transform_count: 42 + transform_time_ms: 61 + transform_yield_count: 14 + insert_time_ms: 1 + insert_new_count: 14 + insert_reused_count: 2 +- query: EXPLAIN select * from t1 where id > 1 + explain: SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG) + task_count: 163 + task_total_time_ms: 72 + transform_count: 42 + transform_time_ms: 61 + transform_yield_count: 14 + insert_time_ms: 1 + insert_new_count: 14 + insert_reused_count: 2 +- query: EXPLAIN select * from t1 where id > 1 + explain: SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG) + task_count: 163 + task_total_time_ms: 72 + transform_count: 42 + transform_time_ms: 61 + transform_yield_count: 14 + insert_time_ms: 1 + insert_new_count: 14 + insert_reused_count: 2 diff --git a/yaml-tests/src/test/resources/simple-query-with-different-debuggers.yamsql b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.yamsql new file mode 100644 index 0000000000..71cc43ecf5 --- /dev/null +++ b/yaml-tests/src/test/resources/simple-query-with-different-debuggers.yamsql @@ -0,0 +1,53 @@ +# +# simple-query-with-different-debuggers.yamsql +# +# This source file is part of the FoundationDB open source project +# +# Copyright 2021-2025 Apple Inc. and the FoundationDB project authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +--- +schema_template: + create table t1(id bigint, col1 string, primary key(id)) +--- +setup: + steps: + - query: INSERT INTO T1 VALUES + (1, 'a'), + (2, 'b'), + (3, 'c') +--- +test_block: + name: simple-query-with-different-debuggers + preset: single_repetition_ordered + tests: + - + - query: select * from t1 where id > 1 + - explain: "SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG)" + - debugger: lightweight + - result: [{id: 2, col1: 'b'}, + {id: 3, col1: 'c'}] + - + - query: select * from t1 where id > 1 + - explain: "SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG)" + - debugger: sane + - result: [{id: 2, col1: 'b'}, + {id: 3, col1: 'c'}] + - + - query: select * from t1 where id > 1 + - explain: "SCAN(<,>) | FILTER _.ID GREATER_THAN promote(@c8 AS LONG)" + - debugger: insane + - result: [{id: 2, col1: 'b'}, + {id: 3, col1: 'c'}] +...