diff --git a/CHANGELOG.md b/CHANGELOG.md index 85b50967e9fb7..a4e2d30ff74a5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), - Introduce a new pull-based ingestion plugin for file-based indexing (for local testing) ([#18591](https://github.com/opensearch-project/OpenSearch/pull/18591)) - Add support for search pipeline in search and msearch template ([#18564](https://github.com/opensearch-project/OpenSearch/pull/18564)) - Add BooleanQuery rewrite moving constant-scoring must clauses to filter clauses ([#18510](https://github.com/opensearch-project/OpenSearch/issues/18510)) +- Add support for non-timing info in profiler ([#18460](https://github.com/opensearch-project/OpenSearch/issues/18460)) ### Changed - Update Subject interface to use CheckedRunnable ([#18570](https://github.com/opensearch-project/OpenSearch/issues/18570)) @@ -37,7 +38,6 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), - Cannot communicate with HTTP/2 when reactor-netty is enabled ([#18599](https://github.com/opensearch-project/OpenSearch/pull/18599)) - Fix the visit of sub queries for HasParentQuery and HasChildQuery ([#18621](https://github.com/opensearch-project/OpenSearch/pull/18621)) - ### Security [Unreleased 3.x]: https://github.com/opensearch-project/OpenSearch/compare/3.1...main diff --git a/server/src/main/java/org/opensearch/search/internal/ContextIndexSearcher.java b/server/src/main/java/org/opensearch/search/internal/ContextIndexSearcher.java index bf570a0dd0d60..4a5159681d07f 100644 --- a/server/src/main/java/org/opensearch/search/internal/ContextIndexSearcher.java +++ b/server/src/main/java/org/opensearch/search/internal/ContextIndexSearcher.java @@ -213,7 +213,7 @@ public Weight createWeight(Query query, ScoreMode scoreMode, float boost) throws // createWeight() is called for each query in the tree, so we tell the queryProfiler // each invocation so that it can build an internal representation of the query // tree - ContextualProfileBreakdown profile = profiler.getQueryBreakdown(query); + ContextualProfileBreakdown profile = profiler.getQueryBreakdown(query); Timer timer = profile.getTimer(QueryTimingType.CREATE_WEIGHT); timer.start(); final Weight weight; diff --git a/server/src/main/java/org/opensearch/search/profile/AbstractInternalProfileTree.java b/server/src/main/java/org/opensearch/search/profile/AbstractInternalProfileTree.java index 904b04b249b1b..f067064cc56f5 100644 --- a/server/src/main/java/org/opensearch/search/profile/AbstractInternalProfileTree.java +++ b/server/src/main/java/org/opensearch/search/profile/AbstractInternalProfileTree.java @@ -45,7 +45,7 @@ * * @opensearch.internal */ -public abstract class AbstractInternalProfileTree, E> { +public abstract class AbstractInternalProfileTree { protected ArrayList breakdowns; /** Maps the Query to it's list of children. This is basically the dependency tree */ diff --git a/server/src/main/java/org/opensearch/search/profile/AbstractProfileBreakdown.java b/server/src/main/java/org/opensearch/search/profile/AbstractProfileBreakdown.java index 4a1563e7cdce9..1bacc26eaa024 100644 --- a/server/src/main/java/org/opensearch/search/profile/AbstractProfileBreakdown.java +++ b/server/src/main/java/org/opensearch/search/profile/AbstractProfileBreakdown.java @@ -32,9 +32,12 @@ package org.opensearch.search.profile; +import java.util.Collection; import java.util.Collections; -import java.util.HashMap; import java.util.Map; +import java.util.TreeMap; +import java.util.function.Supplier; +import java.util.stream.Collectors; import static java.util.Collections.emptyMap; @@ -45,46 +48,46 @@ * * @opensearch.internal */ -public abstract class AbstractProfileBreakdown> { +public abstract class AbstractProfileBreakdown { - /** - * The accumulated timings for this query node - */ - protected final Timer[] timings; - protected final T[] timingTypes; - public static final String TIMING_TYPE_COUNT_SUFFIX = "_count"; - public static final String TIMING_TYPE_START_TIME_SUFFIX = "_start_time"; + protected final Map metrics; /** Sole constructor. */ - public AbstractProfileBreakdown(Class clazz) { - this.timingTypes = clazz.getEnumConstants(); - timings = new Timer[timingTypes.length]; - for (int i = 0; i < timings.length; ++i) { - timings[i] = new Timer(); - } + public AbstractProfileBreakdown(Collection> metricSuppliers) { + this.metrics = metricSuppliers.stream().map(Supplier::get).collect(Collectors.toMap(ProfileMetric::getName, metric -> metric)); } - public Timer getTimer(T timing) { - return timings[timing.ordinal()]; + public Timer getTimer(Enum type) { + ProfileMetric metric = metrics.get(type.toString()); + assert metric instanceof Timer : "Metric " + type + " is not a timer"; + return (Timer) metric; } - public void setTimer(T timing, Timer timer) { - timings[timing.ordinal()] = timer; + public ProfileMetric getMetric(String name) { + return metrics.get(name); } /** - * Build a timing count breakdown for current instance + * Build a breakdown for current instance */ public Map toBreakdownMap() { - Map map = new HashMap<>(this.timings.length * 3); - for (T timingType : this.timingTypes) { - map.put(timingType.toString(), this.timings[timingType.ordinal()].getApproximateTiming()); - map.put(timingType + TIMING_TYPE_COUNT_SUFFIX, this.timings[timingType.ordinal()].getCount()); - map.put(timingType + TIMING_TYPE_START_TIME_SUFFIX, this.timings[timingType.ordinal()].getEarliestTimerStartTime()); + Map map = new TreeMap<>(); + for (Map.Entry entry : metrics.entrySet()) { + map.putAll(entry.getValue().toBreakdownMap()); } return Collections.unmodifiableMap(map); } + public long toNodeTime() { + long total = 0; + for (Map.Entry entry : metrics.entrySet()) { + if (entry.getValue() instanceof Timer t) { + total += t.getApproximateTiming(); + } + } + return total; + } + /** * Fetch extra debugging information. */ @@ -92,11 +95,4 @@ public Map toDebugMap() { return emptyMap(); } - public long toNodeTime() { - long total = 0; - for (T timingType : timingTypes) { - total += timings[timingType.ordinal()].getApproximateTiming(); - } - return total; - } } diff --git a/server/src/main/java/org/opensearch/search/profile/AbstractProfiler.java b/server/src/main/java/org/opensearch/search/profile/AbstractProfiler.java index 4db1cb87a231d..0527bb44e16d4 100644 --- a/server/src/main/java/org/opensearch/search/profile/AbstractProfiler.java +++ b/server/src/main/java/org/opensearch/search/profile/AbstractProfiler.java @@ -39,7 +39,7 @@ * * @opensearch.internal */ -public class AbstractProfiler, E> { +public abstract class AbstractProfiler { protected final AbstractInternalProfileTree profileTree; diff --git a/server/src/main/java/org/opensearch/search/profile/ContextualProfileBreakdown.java b/server/src/main/java/org/opensearch/search/profile/ContextualProfileBreakdown.java index 3fe621321c8ad..2ca88f5cabc85 100644 --- a/server/src/main/java/org/opensearch/search/profile/ContextualProfileBreakdown.java +++ b/server/src/main/java/org/opensearch/search/profile/ContextualProfileBreakdown.java @@ -11,8 +11,10 @@ import org.apache.lucene.index.LeafReaderContext; import org.apache.lucene.search.Collector; +import java.util.Collection; import java.util.List; import java.util.Map; +import java.util.function.Supplier; /** * Provide contextual profile breakdowns which are associated with freestyle context. Used when concurrent @@ -20,9 +22,10 @@ * * @opensearch.internal */ -public abstract class ContextualProfileBreakdown> extends AbstractProfileBreakdown { - public ContextualProfileBreakdown(Class clazz) { - super(clazz); +public abstract class ContextualProfileBreakdown extends AbstractProfileBreakdown { + + public ContextualProfileBreakdown(Collection> metrics) { + super(metrics); } /** @@ -30,7 +33,7 @@ public ContextualProfileBreakdown(Class clazz) { * @param context freestyle context * @return contextual profile breakdown instance */ - public abstract AbstractProfileBreakdown context(Object context); + public abstract AbstractProfileBreakdown context(Object context); public void associateCollectorToLeaves(Collector collector, LeafReaderContext leaf) {} diff --git a/server/src/main/java/org/opensearch/search/profile/ProfileMetric.java b/server/src/main/java/org/opensearch/search/profile/ProfileMetric.java new file mode 100644 index 0000000000000..36bb9b300f3b3 --- /dev/null +++ b/server/src/main/java/org/opensearch/search/profile/ProfileMetric.java @@ -0,0 +1,40 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * The OpenSearch Contributors require contributions made to + * this file be licensed under the Apache-2.0 license or a + * compatible open source license. + */ + +package org.opensearch.search.profile; + +import org.opensearch.common.annotation.ExperimentalApi; + +import java.util.Map; + +/** + * A metric for profiling. + */ +@ExperimentalApi +public abstract class ProfileMetric { + + private final String name; + + public ProfileMetric(String name) { + this.name = name; + } + + /** + * + * @return name of the metric + */ + public String getName() { + return name; + } + + /** + * + * @return map representation of breakdown + */ + abstract public Map toBreakdownMap(); +} diff --git a/server/src/main/java/org/opensearch/search/profile/ProfileMetricUtil.java b/server/src/main/java/org/opensearch/search/profile/ProfileMetricUtil.java new file mode 100644 index 0000000000000..248e29fc0383f --- /dev/null +++ b/server/src/main/java/org/opensearch/search/profile/ProfileMetricUtil.java @@ -0,0 +1,38 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * The OpenSearch Contributors require contributions made to + * this file be licensed under the Apache-2.0 license or a + * compatible open source license. + */ + +package org.opensearch.search.profile; + +import org.opensearch.search.profile.aggregation.AggregationTimingType; +import org.opensearch.search.profile.query.QueryTimingType; + +import java.util.ArrayList; +import java.util.Collection; +import java.util.function.Supplier; + +/** + * Utility class to provide profile metrics to breakdowns. + */ +public class ProfileMetricUtil { + + public static Collection> getDefaultQueryProfileMetrics() { + Collection> metrics = new ArrayList<>(); + for (QueryTimingType type : QueryTimingType.values()) { + metrics.add(() -> new Timer(type.toString())); + } + return metrics; + } + + public static Collection> getAggregationProfileMetrics() { + Collection> metrics = new ArrayList<>(); + for (AggregationTimingType type : AggregationTimingType.values()) { + metrics.add(() -> new Timer(type.toString())); + } + return metrics; + } +} diff --git a/server/src/main/java/org/opensearch/search/profile/ProfileResult.java b/server/src/main/java/org/opensearch/search/profile/ProfileResult.java index 2c0d2cf3ba78a..7969a9e5890bf 100644 --- a/server/src/main/java/org/opensearch/search/profile/ProfileResult.java +++ b/server/src/main/java/org/opensearch/search/profile/ProfileResult.java @@ -271,7 +271,7 @@ static void removeStartTimeFields(Map modifiedBreakdown) { Iterator> iterator = modifiedBreakdown.entrySet().iterator(); while (iterator.hasNext()) { Map.Entry entry = iterator.next(); - if (entry.getKey().endsWith(AbstractProfileBreakdown.TIMING_TYPE_START_TIME_SUFFIX)) { + if (entry.getKey().endsWith(Timer.TIMING_TYPE_START_TIME_SUFFIX)) { iterator.remove(); } } diff --git a/server/src/main/java/org/opensearch/search/profile/Profilers.java b/server/src/main/java/org/opensearch/search/profile/Profilers.java index 75337f89e67ca..5aaf1d670313e 100644 --- a/server/src/main/java/org/opensearch/search/profile/Profilers.java +++ b/server/src/main/java/org/opensearch/search/profile/Profilers.java @@ -79,7 +79,7 @@ public QueryProfiler addQueryProfiler() { /** Get the current profiler. */ public QueryProfiler getCurrentQueryProfiler() { - return queryProfilers.get(queryProfilers.size() - 1); + return queryProfilers.getLast(); } /** Return the list of all created {@link QueryProfiler}s so far. */ diff --git a/server/src/main/java/org/opensearch/search/profile/Timer.java b/server/src/main/java/org/opensearch/search/profile/Timer.java index 864c689cf7fa0..673d05bfdca91 100644 --- a/server/src/main/java/org/opensearch/search/profile/Timer.java +++ b/server/src/main/java/org/opensearch/search/profile/Timer.java @@ -32,6 +32,9 @@ package org.opensearch.search.profile; +import java.util.HashMap; +import java.util.Map; + /** Helps measure how much time is spent running some methods. * The {@link #start()} and {@link #stop()} methods should typically be called * in a try/finally clause with {@link #start()} being called right before the @@ -48,16 +51,19 @@ * * @opensearch.internal */ -public class Timer { +public class Timer extends ProfileMetric { + public static final String TIMING_TYPE_COUNT_SUFFIX = "_count"; + public static final String TIMING_TYPE_START_TIME_SUFFIX = "_start_time"; private boolean doTiming; private long timing, count, lastCount, start, earliestTimerStartTime; - public Timer() { - this(0, 0, 0, 0, 0); + public Timer(String name) { + super(name); } - public Timer(long timing, long count, long lastCount, long start, long earliestTimerStartTime) { + public Timer(long timing, long count, long lastCount, long start, long earliestTimerStartTime, String name) { + super(name); this.timing = timing; this.count = count; this.lastCount = lastCount; @@ -131,4 +137,13 @@ public final long getApproximateTiming() { } return timing; } + + @Override + public Map toBreakdownMap() { + Map map = new HashMap<>(); + map.put(getName(), getApproximateTiming()); + map.put(getName() + TIMING_TYPE_COUNT_SUFFIX, getCount()); + map.put(getName() + TIMING_TYPE_START_TIME_SUFFIX, getEarliestTimerStartTime()); + return map; + } } diff --git a/server/src/main/java/org/opensearch/search/profile/aggregation/AggregationProfileBreakdown.java b/server/src/main/java/org/opensearch/search/profile/aggregation/AggregationProfileBreakdown.java index 8642f0da4a90b..3c99b041a423c 100644 --- a/server/src/main/java/org/opensearch/search/profile/aggregation/AggregationProfileBreakdown.java +++ b/server/src/main/java/org/opensearch/search/profile/aggregation/AggregationProfileBreakdown.java @@ -34,9 +34,13 @@ import org.opensearch.common.annotation.PublicApi; import org.opensearch.search.profile.AbstractProfileBreakdown; +import org.opensearch.search.profile.ProfileMetric; +import org.opensearch.search.profile.ProfileMetricUtil; +import java.util.Collection; import java.util.HashMap; import java.util.Map; +import java.util.function.Supplier; import static java.util.Collections.unmodifiableMap; @@ -46,11 +50,15 @@ * @opensearch.api */ @PublicApi(since = "1.0.0") -public class AggregationProfileBreakdown extends AbstractProfileBreakdown { +public class AggregationProfileBreakdown extends AbstractProfileBreakdown { private final Map extra = new HashMap<>(); public AggregationProfileBreakdown() { - super(AggregationTimingType.class); + this(ProfileMetricUtil.getAggregationProfileMetrics()); + } + + public AggregationProfileBreakdown(Collection> timers) { + super(timers); } /** @@ -64,4 +72,5 @@ public void addDebugInfo(String key, Object value) { public Map toDebugMap() { return unmodifiableMap(extra); } + } diff --git a/server/src/main/java/org/opensearch/search/profile/aggregation/ConcurrentAggregationProfiler.java b/server/src/main/java/org/opensearch/search/profile/aggregation/ConcurrentAggregationProfiler.java index deed68c535cf9..593359cd5c22c 100644 --- a/server/src/main/java/org/opensearch/search/profile/aggregation/ConcurrentAggregationProfiler.java +++ b/server/src/main/java/org/opensearch/search/profile/aggregation/ConcurrentAggregationProfiler.java @@ -13,8 +13,8 @@ package org.opensearch.search.profile.aggregation; -import org.opensearch.search.profile.AbstractProfileBreakdown; import org.opensearch.search.profile.ProfileResult; +import org.opensearch.search.profile.Timer; import java.util.HashMap; import java.util.LinkedList; @@ -31,7 +31,7 @@ public class ConcurrentAggregationProfiler extends AggregationProfiler { private static final String MAX_PREFIX = "max_"; private static final String MIN_PREFIX = "min_"; private static final String AVG_PREFIX = "avg_"; - private static final String START_TIME_KEY = AggregationTimingType.INITIALIZE + AbstractProfileBreakdown.TIMING_TYPE_START_TIME_SUFFIX; + private static final String START_TIME_KEY = AggregationTimingType.INITIALIZE + Timer.TIMING_TYPE_START_TIME_SUFFIX; private static final String[] breakdownCountStatsTypes = { "build_leaf_collector_count", "collect_count" }; @Override @@ -82,8 +82,7 @@ private List reduceProfileResultsTree(List profile // Profiled breakdown total time for (AggregationTimingType timingType : AggregationTimingType.values()) { String breakdownTimingType = timingType.toString(); - Long startTime = profileResult.getTimeBreakdown() - .get(breakdownTimingType + AbstractProfileBreakdown.TIMING_TYPE_START_TIME_SUFFIX); + Long startTime = profileResult.getTimeBreakdown().get(breakdownTimingType + Timer.TIMING_TYPE_START_TIME_SUFFIX); Long endTime = startTime + profileResult.getTimeBreakdown().get(breakdownTimingType); minSliceStartTimeMap.put( breakdownTimingType, @@ -103,7 +102,7 @@ private List reduceProfileResultsTree(List profile // Profiled breakdown count for (AggregationTimingType timingType : AggregationTimingType.values()) { String breakdownType = timingType.toString(); - String breakdownTypeCount = breakdownType + AbstractProfileBreakdown.TIMING_TYPE_COUNT_SUFFIX; + String breakdownTypeCount = breakdownType + Timer.TIMING_TYPE_COUNT_SUFFIX; breakdown.put( breakdownTypeCount, breakdown.getOrDefault(breakdownTypeCount, 0L) + profileResult.getTimeBreakdown().get(breakdownTypeCount) diff --git a/server/src/main/java/org/opensearch/search/profile/query/AbstractQueryProfileTree.java b/server/src/main/java/org/opensearch/search/profile/query/AbstractQueryProfileTree.java index 2f5d632ee2d87..2541bd3887f13 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/AbstractQueryProfileTree.java +++ b/server/src/main/java/org/opensearch/search/profile/query/AbstractQueryProfileTree.java @@ -20,7 +20,7 @@ * * @opensearch.internal */ -public abstract class AbstractQueryProfileTree extends AbstractInternalProfileTree, Query> { +public abstract class AbstractQueryProfileTree extends AbstractInternalProfileTree { /** Rewrite time */ private long rewriteTime; @@ -64,4 +64,6 @@ public void stopAndAddRewriteTime() { public long getRewriteTime() { return rewriteTime; } + + protected abstract ContextualProfileBreakdown createProfileBreakdown(); } diff --git a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdown.java b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdown.java index c017b15bc6d3c..8ee0f0b8ac7e1 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdown.java +++ b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdown.java @@ -13,13 +13,23 @@ import org.opensearch.OpenSearchException; import org.opensearch.search.profile.AbstractProfileBreakdown; import org.opensearch.search.profile.ContextualProfileBreakdown; +import org.opensearch.search.profile.ProfileMetric; +import org.opensearch.search.profile.Timer; import java.util.ArrayList; +import java.util.Collection; import java.util.Collections; import java.util.HashMap; +import java.util.HashSet; import java.util.List; import java.util.Map; +import java.util.Set; +import java.util.TreeMap; import java.util.concurrent.ConcurrentHashMap; +import java.util.function.Supplier; + +import static org.opensearch.search.profile.Timer.TIMING_TYPE_COUNT_SUFFIX; +import static org.opensearch.search.profile.Timer.TIMING_TYPE_START_TIME_SUFFIX; /** * A record of timings for the various operations that may happen during query execution. @@ -28,7 +38,7 @@ * * @opensearch.internal */ -public final class ConcurrentQueryProfileBreakdown extends ContextualProfileBreakdown { +public final class ConcurrentQueryProfileBreakdown extends ContextualProfileBreakdown { static final String SLICE_END_TIME_SUFFIX = "_slice_end_time"; static final String SLICE_START_TIME_SUFFIX = "_slice_start_time"; static final String MAX_PREFIX = "max_"; @@ -40,26 +50,32 @@ public final class ConcurrentQueryProfileBreakdown extends ContextualProfileBrea private long avgSliceNodeTime = 0L; // keep track of all breakdown timings per segment. package-private for testing - private final Map> contexts = new ConcurrentHashMap<>(); + private final Map contexts = new ConcurrentHashMap<>(); // represents slice to leaves mapping as for each slice a unique collector instance is created private final Map> sliceCollectorsToLeaves = new ConcurrentHashMap<>(); - /** Sole constructor. */ - public ConcurrentQueryProfileBreakdown() { - super(QueryTimingType.class); + private final Collection> metricSuppliers; + private final Set timingMetrics; + private final Set nonTimingMetrics; + + public ConcurrentQueryProfileBreakdown(Collection> metricSuppliers) { + super(metricSuppliers); + this.metricSuppliers = metricSuppliers; + this.timingMetrics = getTimingMetrics(); + this.nonTimingMetrics = getNonTimingMetrics(); } @Override - public AbstractProfileBreakdown context(Object context) { + public AbstractProfileBreakdown context(Object context) { // See please https://bugs.openjdk.java.net/browse/JDK-8161372 - final AbstractProfileBreakdown profile = contexts.get(context); + final AbstractProfileBreakdown profile = contexts.get(context); if (profile != null) { return profile; } - return contexts.computeIfAbsent(context, ctx -> new QueryProfileBreakdown()); + return contexts.computeIfAbsent(context, ctx -> new QueryProfileBreakdown(metricSuppliers)); } @Override @@ -87,12 +103,12 @@ public Map toBreakdownMap() { assert contexts.size() == 1 : "Unexpected size: " + contexts.size() + " of leaves breakdown in ConcurrentQueryProfileBreakdown of rewritten query for a leaf."; - AbstractProfileBreakdown breakdown = contexts.values().iterator().next(); + AbstractProfileBreakdown breakdown = contexts.values().iterator().next(); queryNodeTime = breakdown.toNodeTime() + createWeightTime; maxSliceNodeTime = 0L; minSliceNodeTime = 0L; avgSliceNodeTime = 0L; - Map queryBreakdownMap = new HashMap<>(breakdown.toBreakdownMap()); + Map queryBreakdownMap = new TreeMap<>(breakdown.toBreakdownMap()); queryBreakdownMap.put(QueryTimingType.CREATE_WEIGHT.toString(), createWeightTime); queryBreakdownMap.put(QueryTimingType.CREATE_WEIGHT + TIMING_TYPE_COUNT_SUFFIX, 1L); return queryBreakdownMap; @@ -110,19 +126,19 @@ public Map toBreakdownMap() { * default breakdown map. */ private Map buildDefaultQueryBreakdownMap(long createWeightTime) { - final Map concurrentQueryBreakdownMap = new HashMap<>(); + final Map concurrentQueryBreakdownMap = new TreeMap<>(); for (QueryTimingType timingType : QueryTimingType.values()) { final String timingTypeKey = timingType.toString(); - final String timingTypeCountKey = timingTypeKey + TIMING_TYPE_COUNT_SUFFIX; + final String timingTypeCountKey = timingType + TIMING_TYPE_COUNT_SUFFIX; if (timingType.equals(QueryTimingType.CREATE_WEIGHT)) { concurrentQueryBreakdownMap.put(timingTypeKey, createWeightTime); concurrentQueryBreakdownMap.put(timingTypeCountKey, 1L); continue; } - final String maxBreakdownTypeTime = MAX_PREFIX + timingTypeKey; - final String minBreakdownTypeTime = MIN_PREFIX + timingTypeKey; - final String avgBreakdownTypeTime = AVG_PREFIX + timingTypeKey; + final String maxBreakdownTypeTime = MAX_PREFIX + timingType; + final String minBreakdownTypeTime = MIN_PREFIX + timingType; + final String avgBreakdownTypeTime = AVG_PREFIX + timingType; final String maxBreakdownTypeCount = MAX_PREFIX + timingTypeCountKey; final String minBreakdownTypeCount = MIN_PREFIX + timingTypeCountKey; final String avgBreakdownTypeCount = AVG_PREFIX + timingTypeCountKey; @@ -156,8 +172,9 @@ Map> buildSliceLevelBreakdown() { // max slice end time across all timing types long sliceMaxEndTime = Long.MIN_VALUE; long sliceMinStartTime = Long.MAX_VALUE; - for (QueryTimingType timingType : QueryTimingType.values()) { - if (timingType.equals(QueryTimingType.CREATE_WEIGHT)) { + + for (String timingType : timingMetrics) { + if (timingType.equals(QueryTimingType.CREATE_WEIGHT.toString())) { // do nothing for create weight as that is query level time and not slice level continue; } @@ -210,9 +227,7 @@ Map> buildSliceLevelBreakdown() { ); // compute the sliceEndTime for timingType using max of endTime across slice leaves - final long sliceLeafTimingTypeEndTime = sliceLeafTimingTypeStartTime + currentSliceLeafBreakdownMap.get( - timingType.toString() - ); + final long sliceLeafTimingTypeEndTime = sliceLeafTimingTypeStartTime + currentSliceLeafBreakdownMap.get(timingType); currentSliceBreakdown.compute( timingTypeSliceEndTimeKey, (key, value) -> (value == null) ? sliceLeafTimingTypeEndTime : Math.max(value, sliceLeafTimingTypeEndTime) @@ -235,13 +250,28 @@ Map> buildSliceLevelBreakdown() { sliceMinStartTime = Math.min(sliceMinStartTime, currentSliceStartTime); // compute total time for each timing type at slice level using sliceEndTime and sliceStartTime currentSliceBreakdown.put( - timingType.toString(), + timingType, currentSliceBreakdown.getOrDefault(timingTypeSliceEndTimeKey, 0L) - currentSliceBreakdown.getOrDefault( timingTypeSliceStartTimeKey, 0L ) ); } + + for (String metric : nonTimingMetrics) { + for (LeafReaderContext sliceLeaf : slice.getValue()) { + if (!contexts.containsKey(sliceLeaf)) { + continue; + } + final Map currentSliceLeafBreakdownMap = contexts.get(sliceLeaf).toBreakdownMap(); + final long sliceLeafMetricValue = currentSliceLeafBreakdownMap.get(metric); + currentSliceBreakdown.compute( + metric, + (key, value) -> (value == null) ? sliceLeafMetricValue : value + sliceLeafMetricValue + ); + } + } + // currentSliceNodeTime does not include the create weight time, as that is computed in non-concurrent part long currentSliceNodeTime; if (sliceMinStartTime == Long.MAX_VALUE && sliceMaxEndTime == Long.MIN_VALUE) { @@ -284,17 +314,27 @@ public Map buildQueryBreakdownMap( long createWeightTime, long createWeightStartTime ) { - final Map queryBreakdownMap = new HashMap<>(); + final Map queryBreakdownMap = new TreeMap<>(); long queryEndTime = Long.MIN_VALUE; - for (QueryTimingType queryTimingType : QueryTimingType.values()) { - final String timingTypeKey = queryTimingType.toString(); - final String timingTypeCountKey = timingTypeKey + TIMING_TYPE_COUNT_SUFFIX; - final String sliceEndTimeForTimingType = timingTypeKey + SLICE_END_TIME_SUFFIX; - final String sliceStartTimeForTimingType = timingTypeKey + SLICE_START_TIME_SUFFIX; - - final String maxBreakdownTypeTime = MAX_PREFIX + timingTypeKey; - final String minBreakdownTypeTime = MIN_PREFIX + timingTypeKey; - final String avgBreakdownTypeTime = AVG_PREFIX + timingTypeKey; + + // the create weight time is computed at the query level and is called only once per query + queryBreakdownMap.put(QueryTimingType.CREATE_WEIGHT + TIMING_TYPE_COUNT_SUFFIX, 1L); + queryBreakdownMap.put(QueryTimingType.CREATE_WEIGHT.toString(), createWeightTime); + + for (String metric : timingMetrics) { + + if (metric.equals(QueryTimingType.CREATE_WEIGHT.toString())) { + // create weight time is computed at query level and is called only once per query + continue; + } + + final String timingTypeCountKey = metric + TIMING_TYPE_COUNT_SUFFIX; + final String sliceEndTimeForTimingType = metric + SLICE_END_TIME_SUFFIX; + final String sliceStartTimeForTimingType = metric + SLICE_START_TIME_SUFFIX; + + final String maxBreakdownTypeTime = MAX_PREFIX + metric; + final String minBreakdownTypeTime = MIN_PREFIX + metric; + final String avgBreakdownTypeTime = AVG_PREFIX + metric; final String maxBreakdownTypeCount = MAX_PREFIX + timingTypeCountKey; final String minBreakdownTypeCount = MIN_PREFIX + timingTypeCountKey; final String avgBreakdownTypeCount = AVG_PREFIX + timingTypeCountKey; @@ -303,43 +343,19 @@ public Map buildQueryBreakdownMap( long queryTimingTypeStartTime = Long.MAX_VALUE; long queryTimingTypeCount = 0L; - // the create weight time is computed at the query level and is called only once per query - if (queryTimingType == QueryTimingType.CREATE_WEIGHT) { - queryBreakdownMap.put(timingTypeCountKey, 1L); - queryBreakdownMap.put(timingTypeKey, createWeightTime); - continue; - } - // for all other timing types, we will compute min/max/avg/total across slices for (Map.Entry> sliceBreakdown : sliceLevelBreakdowns.entrySet()) { - long sliceBreakdownTypeTime = sliceBreakdown.getValue().getOrDefault(timingTypeKey, 0L); + long sliceBreakdownTypeTime = sliceBreakdown.getValue().getOrDefault(metric, 0L); long sliceBreakdownTypeCount = sliceBreakdown.getValue().getOrDefault(timingTypeCountKey, 0L); // compute max/min/avg TimingType time across slices - queryBreakdownMap.compute( - maxBreakdownTypeTime, - (key, value) -> (value == null) ? sliceBreakdownTypeTime : Math.max(sliceBreakdownTypeTime, value) - ); - queryBreakdownMap.compute( - minBreakdownTypeTime, - (key, value) -> (value == null) ? sliceBreakdownTypeTime : Math.min(sliceBreakdownTypeTime, value) - ); - queryBreakdownMap.compute( - avgBreakdownTypeTime, - (key, value) -> (value == null) ? sliceBreakdownTypeTime : sliceBreakdownTypeTime + value - ); - + addStatsToMap(queryBreakdownMap, maxBreakdownTypeTime, minBreakdownTypeTime, avgBreakdownTypeTime, sliceBreakdownTypeTime); // compute max/min/avg TimingType count across slices - queryBreakdownMap.compute( + addStatsToMap( + queryBreakdownMap, maxBreakdownTypeCount, - (key, value) -> (value == null) ? sliceBreakdownTypeCount : Math.max(sliceBreakdownTypeCount, value) - ); - queryBreakdownMap.compute( minBreakdownTypeCount, - (key, value) -> (value == null) ? sliceBreakdownTypeCount : Math.min(sliceBreakdownTypeCount, value) - ); - queryBreakdownMap.compute( avgBreakdownTypeCount, - (key, value) -> (value == null) ? sliceBreakdownTypeCount : sliceBreakdownTypeCount + value + sliceBreakdownTypeCount ); // only modify the start/end time of the TimingType if the slice used the timer @@ -360,7 +376,7 @@ public Map buildQueryBreakdownMap( if (queryTimingTypeCount > 0L && (queryTimingTypeStartTime == Long.MAX_VALUE || queryTimingTypeEndTime == Long.MIN_VALUE)) { throw new OpenSearchException( "Unexpected timing type [" - + timingTypeKey + + metric + "] start [" + queryTimingTypeStartTime + "] or end time [" @@ -368,13 +384,33 @@ public Map buildQueryBreakdownMap( + "] computed across slices for profile results" ); } - queryBreakdownMap.put(timingTypeKey, (queryTimingTypeCount > 0L) ? queryTimingTypeEndTime - queryTimingTypeStartTime : 0L); + queryBreakdownMap.put(metric, (queryTimingTypeCount > 0L) ? queryTimingTypeEndTime - queryTimingTypeStartTime : 0L); queryBreakdownMap.put(timingTypeCountKey, queryTimingTypeCount); queryBreakdownMap.compute(avgBreakdownTypeTime, (key, value) -> (value == null) ? 0L : value / sliceLevelBreakdowns.size()); queryBreakdownMap.compute(avgBreakdownTypeCount, (key, value) -> (value == null) ? 0L : value / sliceLevelBreakdowns.size()); // compute query end time using max of query end time across all timing types queryEndTime = Math.max(queryEndTime, queryTimingTypeEndTime); } + + for (String metric : nonTimingMetrics) { + + final String maxBreakdownTypeTime = MAX_PREFIX + metric; + final String minBreakdownTypeTime = MIN_PREFIX + metric; + final String avgBreakdownTypeTime = AVG_PREFIX + metric; + + long totalBreakdownValue = 0L; + + // for all other timing types, we will compute min/max/avg/total across slices + for (Map.Entry> sliceBreakdown : sliceLevelBreakdowns.entrySet()) { + long sliceBreakdownValue = sliceBreakdown.getValue().getOrDefault(metric, 0L); + // compute max/min/avg TimingType time across slices + addStatsToMap(queryBreakdownMap, maxBreakdownTypeTime, minBreakdownTypeTime, avgBreakdownTypeTime, sliceBreakdownValue); + totalBreakdownValue += sliceBreakdownValue; + } + queryBreakdownMap.put(metric, totalBreakdownValue); + queryBreakdownMap.compute(avgBreakdownTypeTime, (key, value) -> (value == null) ? 0L : value / sliceLevelBreakdowns.size()); + } + if (queryEndTime == Long.MIN_VALUE) { throw new OpenSearchException("Unexpected error while computing the query end time across slices in profile result"); } @@ -382,6 +418,32 @@ public Map buildQueryBreakdownMap( return queryBreakdownMap; } + private void addStatsToMap(Map queryBreakdownMap, String maxKey, String minKey, String avgKey, long sliceValue) { + queryBreakdownMap.compute(maxKey, (key, value) -> (value == null) ? sliceValue : Math.max(sliceValue, value)); + queryBreakdownMap.compute(minKey, (key, value) -> (value == null) ? sliceValue : Math.min(sliceValue, value)); + queryBreakdownMap.compute(avgKey, (key, value) -> (value == null) ? sliceValue : (value + sliceValue)); + } + + private Set getTimingMetrics() { + Set result = new HashSet<>(); + for (Map.Entry entry : metrics.entrySet()) { + if (entry.getValue() instanceof org.opensearch.search.profile.Timer) { + result.add(entry.getKey()); + } + } + return result; + } + + private Set getNonTimingMetrics() { + Set result = new HashSet<>(); + for (Map.Entry entry : metrics.entrySet()) { + if (!(entry.getValue() instanceof Timer)) { + result.add(entry.getKey()); + } + } + return result; + } + @Override public long toNodeTime() { return queryNodeTime; @@ -403,7 +465,7 @@ Map> getSliceCollectorsToLeaves() { } // used by tests - Map> getContexts() { + Map getContexts() { return contexts; } @@ -418,4 +480,5 @@ long getMinSliceNodeTime() { long getAvgSliceNodeTime() { return avgSliceNodeTime; } + } diff --git a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileTree.java b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileTree.java index 4e54178c3b4fb..ae549a5e9cbe2 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileTree.java +++ b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfileTree.java @@ -11,6 +11,7 @@ import org.apache.lucene.index.LeafReaderContext; import org.apache.lucene.search.Collector; import org.opensearch.search.profile.ContextualProfileBreakdown; +import org.opensearch.search.profile.ProfileMetricUtil; import org.opensearch.search.profile.ProfileResult; import java.util.List; @@ -24,15 +25,15 @@ public class ConcurrentQueryProfileTree extends AbstractQueryProfileTree { @Override - protected ContextualProfileBreakdown createProfileBreakdown() { - return new ConcurrentQueryProfileBreakdown(); + protected ContextualProfileBreakdown createProfileBreakdown() { + return new ConcurrentQueryProfileBreakdown(ProfileMetricUtil.getDefaultQueryProfileMetrics()); } @Override protected ProfileResult createProfileResult( String type, String description, - ContextualProfileBreakdown breakdown, + ContextualProfileBreakdown breakdown, List childrenProfileResults ) { assert breakdown instanceof ConcurrentQueryProfileBreakdown; @@ -62,7 +63,7 @@ protected ProfileResult createProfileResult( @Override public List getTree() { for (Integer root : roots) { - final ContextualProfileBreakdown parentBreakdown = breakdowns.get(root); + final ContextualProfileBreakdown parentBreakdown = breakdowns.get(root); assert parentBreakdown instanceof ConcurrentQueryProfileBreakdown; final Map> parentCollectorToLeaves = ((ConcurrentQueryProfileBreakdown) parentBreakdown) .getSliceCollectorsToLeaves(); @@ -82,7 +83,7 @@ private void updateCollectorToLeavesForChildBreakdowns(Integer parentToken, Map< final List children = tree.get(parentToken); if (children != null) { for (Integer currentChild : children) { - final ContextualProfileBreakdown currentChildBreakdown = breakdowns.get(currentChild); + final ContextualProfileBreakdown currentChildBreakdown = breakdowns.get(currentChild); currentChildBreakdown.associateCollectorsToLeaves(collectorToLeaves); updateCollectorToLeavesForChildBreakdowns(currentChild, collectorToLeaves); } diff --git a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfiler.java b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfiler.java index e02e562d766a0..3bce0ecd5c252 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfiler.java +++ b/server/src/main/java/org/opensearch/search/profile/query/ConcurrentQueryProfiler.java @@ -45,7 +45,7 @@ public ConcurrentQueryProfiler(AbstractQueryProfileTree profileTree) { } @Override - public ContextualProfileBreakdown getQueryBreakdown(Query query) { + public ContextualProfileBreakdown getQueryBreakdown(Query query) { ConcurrentQueryProfileTree profileTree = threadToProfileTree.computeIfAbsent( getCurrentThreadId(), k -> new ConcurrentQueryProfileTree() @@ -81,7 +81,7 @@ public List getTree() { */ @Override public void startRewriteTime() { - Timer rewriteTimer = new Timer(); + Timer rewriteTimer = new Timer("rewrite_timer"); threadToRewriteTimers.computeIfAbsent(getCurrentThreadId(), k -> new LinkedList<>()).add(rewriteTimer); rewriteTimer.start(); } diff --git a/server/src/main/java/org/opensearch/search/profile/query/InternalQueryProfileTree.java b/server/src/main/java/org/opensearch/search/profile/query/InternalQueryProfileTree.java index 1ed367f094fb7..14dd0bc853fa0 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/InternalQueryProfileTree.java +++ b/server/src/main/java/org/opensearch/search/profile/query/InternalQueryProfileTree.java @@ -33,6 +33,7 @@ package org.opensearch.search.profile.query; import org.opensearch.search.profile.ContextualProfileBreakdown; +import org.opensearch.search.profile.ProfileMetricUtil; import org.opensearch.search.profile.ProfileResult; /** @@ -43,7 +44,7 @@ public class InternalQueryProfileTree extends AbstractQueryProfileTree { @Override - protected ContextualProfileBreakdown createProfileBreakdown() { - return new QueryProfileBreakdown(); + protected ContextualProfileBreakdown createProfileBreakdown() { + return new QueryProfileBreakdown(ProfileMetricUtil.getDefaultQueryProfileMetrics()); } } diff --git a/server/src/main/java/org/opensearch/search/profile/query/ProfileScorer.java b/server/src/main/java/org/opensearch/search/profile/query/ProfileScorer.java index 28b693ee03ad5..b78ecf4501ae1 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/ProfileScorer.java +++ b/server/src/main/java/org/opensearch/search/profile/query/ProfileScorer.java @@ -54,7 +54,7 @@ final class ProfileScorer extends Scorer { private final Timer scoreTimer, nextDocTimer, advanceTimer, matchTimer, shallowAdvanceTimer, computeMaxScoreTimer, setMinCompetitiveScoreTimer; - ProfileScorer(Scorer scorer, AbstractProfileBreakdown profile) throws IOException { + ProfileScorer(Scorer scorer, AbstractProfileBreakdown profile) throws IOException { this.scorer = scorer; scoreTimer = profile.getTimer(QueryTimingType.SCORE); nextDocTimer = profile.getTimer(QueryTimingType.NEXT_DOC); diff --git a/server/src/main/java/org/opensearch/search/profile/query/ProfileWeight.java b/server/src/main/java/org/opensearch/search/profile/query/ProfileWeight.java index f190a9734c1a5..c200ebc6ba8f0 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/ProfileWeight.java +++ b/server/src/main/java/org/opensearch/search/profile/query/ProfileWeight.java @@ -54,9 +54,9 @@ public final class ProfileWeight extends Weight { private final Weight subQueryWeight; - private final ContextualProfileBreakdown profile; + private final ContextualProfileBreakdown profile; - public ProfileWeight(Query query, Weight subQueryWeight, ContextualProfileBreakdown profile) throws IOException { + public ProfileWeight(Query query, Weight subQueryWeight, ContextualProfileBreakdown profile) throws IOException { super(query); this.subQueryWeight = subQueryWeight; this.profile = profile; diff --git a/server/src/main/java/org/opensearch/search/profile/query/QueryProfileBreakdown.java b/server/src/main/java/org/opensearch/search/profile/query/QueryProfileBreakdown.java index 3514a80e39d85..873c7dc22df65 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/QueryProfileBreakdown.java +++ b/server/src/main/java/org/opensearch/search/profile/query/QueryProfileBreakdown.java @@ -34,6 +34,10 @@ import org.opensearch.search.profile.AbstractProfileBreakdown; import org.opensearch.search.profile.ContextualProfileBreakdown; +import org.opensearch.search.profile.ProfileMetric; + +import java.util.Collection; +import java.util.function.Supplier; /** * A record of timings for the various operations that may happen during query execution. @@ -42,15 +46,15 @@ * * @opensearch.internal */ -public final class QueryProfileBreakdown extends ContextualProfileBreakdown { +public final class QueryProfileBreakdown extends ContextualProfileBreakdown { - /** Sole constructor. */ - public QueryProfileBreakdown() { - super(QueryTimingType.class); + public QueryProfileBreakdown(Collection> metrics) { + super(metrics); } @Override - public AbstractProfileBreakdown context(Object context) { + public AbstractProfileBreakdown context(Object context) { return this; } + } diff --git a/server/src/main/java/org/opensearch/search/profile/query/QueryProfiler.java b/server/src/main/java/org/opensearch/search/profile/query/QueryProfiler.java index 78e65c5bfa257..9791f9af2035c 100644 --- a/server/src/main/java/org/opensearch/search/profile/query/QueryProfiler.java +++ b/server/src/main/java/org/opensearch/search/profile/query/QueryProfiler.java @@ -53,7 +53,7 @@ * @opensearch.api */ @PublicApi(since = "1.0.0") -public class QueryProfiler extends AbstractProfiler, Query> { +public class QueryProfiler extends AbstractProfiler { /** * The root Collector used in the search diff --git a/server/src/test/java/org/opensearch/search/profile/AbstractProfileBreakdownTests.java b/server/src/test/java/org/opensearch/search/profile/AbstractProfileBreakdownTests.java new file mode 100644 index 0000000000000..bfc2092ee7b0f --- /dev/null +++ b/server/src/test/java/org/opensearch/search/profile/AbstractProfileBreakdownTests.java @@ -0,0 +1,61 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * The OpenSearch Contributors require contributions made to + * this file be licensed under the Apache-2.0 license or a + * compatible open source license. + */ + +package org.opensearch.search.profile; + +import org.opensearch.test.OpenSearchTestCase; + +import java.util.Collections; +import java.util.HashMap; +import java.util.List; +import java.util.Locale; +import java.util.Map; + +public class AbstractProfileBreakdownTests extends OpenSearchTestCase { + private enum TestType { + STAT_1, + STAT_2; + + @Override + public String toString() { + return name().toLowerCase(Locale.ROOT); + } + } + + private static class TestProfileBreakdown extends AbstractProfileBreakdown { + Map stats; + + TestProfileBreakdown() { + super(List.of()); + stats = new HashMap(); + long counter = 123; + for (TestType type : TestType.values()) { + stats.put(type.toString(), counter++); + } + } + + @Override + public Map toBreakdownMap() { + return Collections.unmodifiableMap(stats); + } + + @Override + public Map toDebugMap() { + return Map.of("test_debug", 1234L); + } + } + + public void testToBreakdownMap() { + AbstractProfileBreakdown breakdown = new TestProfileBreakdown(); + Map stats = new HashMap<>(); + stats.put("stat_1", 123L); + stats.put("stat_2", 124L); + assertEquals(stats, breakdown.toBreakdownMap()); + assertEquals(Collections.singletonMap("test_debug", 1234L), breakdown.toDebugMap()); + } +} diff --git a/server/src/test/java/org/opensearch/search/profile/ProfileMetricTests.java b/server/src/test/java/org/opensearch/search/profile/ProfileMetricTests.java new file mode 100644 index 0000000000000..453573b97c96a --- /dev/null +++ b/server/src/test/java/org/opensearch/search/profile/ProfileMetricTests.java @@ -0,0 +1,49 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * The OpenSearch Contributors require contributions made to + * this file be licensed under the Apache-2.0 license or a + * compatible open source license. + */ + +package org.opensearch.search.profile; + +import org.opensearch.test.OpenSearchTestCase; + +import java.util.Collection; +import java.util.List; +import java.util.Map; +import java.util.function.Supplier; + +public class ProfileMetricTests extends OpenSearchTestCase { + + private static class TestMetric extends ProfileMetric { + + private long value = 0L; + + public TestMetric(String name) { + super(name); + } + + public void setValue(long value) { + this.value = value; + } + + @Override + public Map toBreakdownMap() { + return Map.of("test_metric", value); + } + } + + public void testNonTimingMetric() { + TestMetric test_metric = new TestMetric("test_metric"); + test_metric.setValue(1234L); + assertEquals(test_metric.getName(), "test_metric"); + Map map = test_metric.toBreakdownMap(); + assertEquals(map.get("test_metric").longValue(), 1234L); + } + + public static Collection> getNonTimingMetric() { + return List.of(() -> new TestMetric("test_metric")); + } +} diff --git a/server/src/test/java/org/opensearch/search/profile/TimerTests.java b/server/src/test/java/org/opensearch/search/profile/TimerTests.java index 5997292eb8f56..8634522dedcda 100644 --- a/server/src/test/java/org/opensearch/search/profile/TimerTests.java +++ b/server/src/test/java/org/opensearch/search/profile/TimerTests.java @@ -34,13 +34,14 @@ import org.opensearch.test.OpenSearchTestCase; +import java.util.Map; import java.util.concurrent.atomic.AtomicLong; public class TimerTests extends OpenSearchTestCase { public void testTimingInterval() { final AtomicLong nanoTimeCallCounter = new AtomicLong(); - Timer t = new Timer() { + Timer t = new Timer("test") { long time = 50; @Override @@ -63,7 +64,7 @@ long nanoTime() { } public void testExtrapolate() { - Timer t = new Timer() { + Timer t = new Timer("test") { long time = 50; @Override @@ -84,4 +85,16 @@ long nanoTime() { } } + public void testTimerBreakdownMap() { + Timer t = new Timer(123L, 2L, 1234L, 0L, 12345L, "test"); + Map map = t.toBreakdownMap(); + assertEquals(map.size(), 3); + assertEquals(map.get("test").longValue(), 123L); + assertEquals(map.get("test_count").longValue(), 2L); + assertEquals(map.get("test_start_time").longValue(), 12345L); + + Timer t1 = new Timer(123L, 2L, 1234L, 0L, 12345L, "test1"); + assertEquals(t1.getName(), "test1"); + } + } diff --git a/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdownTests.java b/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdownTests.java index db14eb90ef839..d3bea3bd4c5ce 100644 --- a/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdownTests.java +++ b/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfileBreakdownTests.java @@ -25,16 +25,22 @@ import org.apache.lucene.index.Term; import org.apache.lucene.search.Collector; import org.apache.lucene.store.Directory; -import org.opensearch.search.profile.AbstractProfileBreakdown; +import org.opensearch.search.profile.ContextualProfileBreakdown; +import org.opensearch.search.profile.ProfileMetric; +import org.opensearch.search.profile.ProfileMetricTests; +import org.opensearch.search.profile.ProfileMetricUtil; import org.opensearch.search.profile.Timer; import org.opensearch.test.OpenSearchTestCase; import org.junit.Before; +import java.util.Collection; import java.util.HashMap; +import java.util.List; import java.util.Map; +import java.util.function.Supplier; -import static org.opensearch.search.profile.AbstractProfileBreakdown.TIMING_TYPE_COUNT_SUFFIX; -import static org.opensearch.search.profile.AbstractProfileBreakdown.TIMING_TYPE_START_TIME_SUFFIX; +import static org.opensearch.search.profile.Timer.TIMING_TYPE_COUNT_SUFFIX; +import static org.opensearch.search.profile.Timer.TIMING_TYPE_START_TIME_SUFFIX; import static org.opensearch.search.profile.query.ConcurrentQueryProfileBreakdown.MIN_PREFIX; import static org.opensearch.search.profile.query.ConcurrentQueryProfileBreakdown.SLICE_END_TIME_SUFFIX; import static org.opensearch.search.profile.query.ConcurrentQueryProfileBreakdown.SLICE_START_TIME_SUFFIX; @@ -42,11 +48,15 @@ public class ConcurrentQueryProfileBreakdownTests extends OpenSearchTestCase { private ConcurrentQueryProfileBreakdown testQueryProfileBreakdown; + private ConcurrentQueryProfileBreakdown testQueryProfileBreakdownCombined; private Timer createWeightTimer; @Before public void setup() { - testQueryProfileBreakdown = new ConcurrentQueryProfileBreakdown(); + testQueryProfileBreakdown = new ConcurrentQueryProfileBreakdown(ProfileMetricUtil.getDefaultQueryProfileMetrics()); + Collection> combinedMetrics = ProfileMetricUtil.getDefaultQueryProfileMetrics(); + combinedMetrics.addAll(ProfileMetricTests.getNonTimingMetric()); + testQueryProfileBreakdownCombined = new ConcurrentQueryProfileBreakdown(combinedMetrics); createWeightTimer = testQueryProfileBreakdown.getTimer(QueryTimingType.CREATE_WEIGHT); try { createWeightTimer.start(); @@ -105,10 +115,7 @@ public void testBuildSliceLevelBreakdownWithSingleSlice() throws Exception { final long createWeightEarliestStartTime = createWeightTimer.getEarliestTimerStartTime(); final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); final Map leafProfileBreakdownMap = getLeafBreakdownMap(createWeightEndTime + 10, 10, 1); - final AbstractProfileBreakdown leafProfileBreakdown = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap - ); + final ContextualProfileBreakdown leafProfileBreakdown = new TestQueryProfileBreakdown(leafProfileBreakdownMap); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector, sliceLeaf); testQueryProfileBreakdown.getContexts().put(sliceLeaf, leafProfileBreakdown); final Map> sliceBreakdownMap = testQueryProfileBreakdown.buildSliceLevelBreakdown(); @@ -156,14 +163,8 @@ public void testBuildSliceLevelBreakdownWithMultipleSlices() throws Exception { final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); final Map leafProfileBreakdownMap_1 = getLeafBreakdownMap(createWeightEndTime + 10, 10, 1); final Map leafProfileBreakdownMap_2 = getLeafBreakdownMap(createWeightEndTime + 40, 10, 1); - final AbstractProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_1 - ); - final AbstractProfileBreakdown leafProfileBreakdown_2 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_2 - ); + final ContextualProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_1); + final ContextualProfileBreakdown leafProfileBreakdown_2 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_2); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_1, directoryReader.leaves().get(0)); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_2, directoryReader.leaves().get(1)); testQueryProfileBreakdown.getContexts().put(directoryReader.leaves().get(0), leafProfileBreakdown_1); @@ -222,14 +223,8 @@ public void testBreakDownMapWithMultipleSlices() throws Exception { final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); final Map leafProfileBreakdownMap_1 = getLeafBreakdownMap(createWeightEndTime + 10, 10, 1); final Map leafProfileBreakdownMap_2 = getLeafBreakdownMap(createWeightEndTime + 40, 20, 1); - final AbstractProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_1 - ); - final AbstractProfileBreakdown leafProfileBreakdown_2 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_2 - ); + final ContextualProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_1); + final ContextualProfileBreakdown leafProfileBreakdown_2 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_2); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_1, directoryReader.leaves().get(0)); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_2, directoryReader.leaves().get(1)); testQueryProfileBreakdown.getContexts().put(directoryReader.leaves().get(0), leafProfileBreakdown_1); @@ -283,10 +278,7 @@ public void testBreakDownMapWithMultipleSlicesAndOneSliceWithNoLeafContext() thr final long createWeightEarliestStartTime = createWeightTimer.getEarliestTimerStartTime(); final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); final Map leafProfileBreakdownMap_1 = getLeafBreakdownMap(createWeightEndTime + 10, 10, 1); - final AbstractProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_1 - ); + final ContextualProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_1); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_1, directoryReader.leaves().get(0)); testQueryProfileBreakdown.associateCollectorToLeaves(sliceCollector_2, directoryReader.leaves().get(1)); testQueryProfileBreakdown.getContexts().put(directoryReader.leaves().get(0), leafProfileBreakdown_1); @@ -339,10 +331,7 @@ public void testOneLeafContextWithEmptySliceCollectorsToLeaves() throws Exceptio final long createWeightEarliestStartTime = createWeightTimer.getEarliestTimerStartTime(); final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); final Map leafProfileBreakdownMap_1 = getLeafBreakdownMap(createWeightEndTime + 10, 10, 1); - final AbstractProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown( - QueryTimingType.class, - leafProfileBreakdownMap_1 - ); + final ContextualProfileBreakdown leafProfileBreakdown_1 = new TestQueryProfileBreakdown(leafProfileBreakdownMap_1); testQueryProfileBreakdown.getContexts().put(directoryReader.leaves().get(0), leafProfileBreakdown_1); final Map queryBreakDownMap = testQueryProfileBreakdown.toBreakdownMap(); assertFalse(queryBreakDownMap == null || queryBreakDownMap.isEmpty()); @@ -385,6 +374,54 @@ public void testOneLeafContextWithEmptySliceCollectorsToLeaves() throws Exceptio directory.close(); } + public void testBuildSliceLevelBreakdownWithSingleSliceCombinedMetricOnly() throws Exception { + final DirectoryReader directoryReader = getDirectoryReader(1); + final Directory directory = directoryReader.directory(); + final LeafReaderContext sliceLeaf = directoryReader.leaves().get(0); + final Collector sliceCollector = mock(Collector.class); + final long createWeightEarliestStartTime = createWeightTimer.getEarliestTimerStartTime(); + final long createWeightEndTime = createWeightEarliestStartTime + createWeightTimer.getApproximateTiming(); + final Map leafProfileBreakdownMap = getCombinedLeafBreakdownMap(createWeightEndTime + 10, 10, 1); + final ContextualProfileBreakdown leafProfileBreakdown = new TestQueryProfileBreakdown(leafProfileBreakdownMap); + testQueryProfileBreakdownCombined.associateCollectorToLeaves(sliceCollector, sliceLeaf); + testQueryProfileBreakdownCombined.getContexts().put(sliceLeaf, leafProfileBreakdown); + final Map> sliceBreakdownMap = testQueryProfileBreakdownCombined.buildSliceLevelBreakdown(); + assertFalse(sliceBreakdownMap == null || sliceBreakdownMap.isEmpty()); + assertEquals(1, sliceBreakdownMap.size()); + assertTrue(sliceBreakdownMap.containsKey(sliceCollector)); + + final Map sliceBreakdown = sliceBreakdownMap.entrySet().iterator().next().getValue(); + for (QueryTimingType timingType : QueryTimingType.values()) { + String timingTypeKey = timingType.toString(); + String timingTypeCountKey = timingTypeKey + TIMING_TYPE_COUNT_SUFFIX; + + if (timingType.equals(QueryTimingType.CREATE_WEIGHT)) { + // there should be no entry for create weight at slice level breakdown map + assertNull(sliceBreakdown.get(timingTypeKey)); + assertNull(sliceBreakdown.get(timingTypeCountKey)); + continue; + } + + // for other timing type we will have all the value and will be same as leaf breakdown as there is single slice and single leaf + assertEquals(leafProfileBreakdownMap.get(timingTypeKey), sliceBreakdown.get(timingTypeKey)); + assertEquals(leafProfileBreakdownMap.get(timingTypeCountKey), sliceBreakdown.get(timingTypeCountKey)); + assertEquals( + leafProfileBreakdownMap.get(timingTypeKey + TIMING_TYPE_START_TIME_SUFFIX), + sliceBreakdown.get(timingTypeKey + SLICE_START_TIME_SUFFIX) + ); + assertEquals( + leafProfileBreakdownMap.get(timingTypeKey + TIMING_TYPE_START_TIME_SUFFIX) + leafProfileBreakdownMap.get(timingTypeKey), + (long) sliceBreakdown.get(timingTypeKey + SLICE_END_TIME_SUFFIX) + ); + } + assertEquals(leafProfileBreakdownMap.get("value"), sliceBreakdown.get("value")); + assertEquals(10, testQueryProfileBreakdownCombined.getMaxSliceNodeTime()); + assertEquals(10, testQueryProfileBreakdownCombined.getMinSliceNodeTime()); + assertEquals(10, testQueryProfileBreakdownCombined.getAvgSliceNodeTime()); + directoryReader.close(); + directory.close(); + } + private Map getLeafBreakdownMap(long startTime, long timeTaken, long count) { Map leafBreakDownMap = new HashMap<>(); for (QueryTimingType timingType : QueryTimingType.values()) { @@ -400,6 +437,22 @@ private Map getLeafBreakdownMap(long startTime, long timeTaken, lo return leafBreakDownMap; } + private Map getCombinedLeafBreakdownMap(long startTime, long timeTaken, long count) { + Map leafBreakDownMap = new HashMap<>(); + for (QueryTimingType timingType : QueryTimingType.values()) { + if (timingType.equals(QueryTimingType.CREATE_WEIGHT)) { + // don't add anything + continue; + } + String timingTypeKey = timingType.toString(); + leafBreakDownMap.put(timingTypeKey, timeTaken); + leafBreakDownMap.put(timingTypeKey + TIMING_TYPE_COUNT_SUFFIX, count); + leafBreakDownMap.put(timingTypeKey + TIMING_TYPE_START_TIME_SUFFIX, startTime); + } + leafBreakDownMap.put("test_metric", 123L); + return leafBreakDownMap; + } + private DirectoryReader getDirectoryReader(int numLeaves) throws Exception { final Directory directory = newDirectory(); IndexWriter iw = new IndexWriter(directory, new IndexWriterConfig(new StandardAnalyzer()).setMergePolicy(NoMergePolicy.INSTANCE)); @@ -416,11 +469,11 @@ private DirectoryReader getDirectoryReader(int numLeaves) throws Exception { return DirectoryReader.open(directory); } - private static class TestQueryProfileBreakdown extends AbstractProfileBreakdown { + private static class TestQueryProfileBreakdown extends ContextualProfileBreakdown { private Map breakdownMap; - public TestQueryProfileBreakdown(Class clazz, Map breakdownMap) { - super(clazz); + public TestQueryProfileBreakdown(Map breakdownMap) { + super(List.of()); this.breakdownMap = breakdownMap; } @@ -428,5 +481,10 @@ public TestQueryProfileBreakdown(Class clazz, Map public Map toBreakdownMap() { return breakdownMap; } + + @Override + public ContextualProfileBreakdown context(Object context) { + return null; + } } } diff --git a/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfilerTests.java b/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfilerTests.java index 736bbcdd9e8dd..2a40c7608feaa 100644 --- a/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfilerTests.java +++ b/server/src/test/java/org/opensearch/search/profile/query/ConcurrentQueryProfilerTests.java @@ -21,9 +21,9 @@ public class ConcurrentQueryProfilerTests extends OpenSearchTestCase { public void testMergeRewriteTimeIntervals() { ConcurrentQueryProfiler profiler = new ConcurrentQueryProfiler(new ConcurrentQueryProfileTree()); List timers = new LinkedList<>(); - timers.add(new Timer(217134L, 1L, 1L, 0L, 553074511206907L)); - timers.add(new Timer(228954L, 1L, 1L, 0L, 553074509287335L)); - timers.add(new Timer(228954L, 1L, 1L, 0L, 553074509287336L)); + timers.add(new Timer(217134L, 1L, 1L, 0L, 553074511206907L, "test1")); + timers.add(new Timer(228954L, 1L, 1L, 0L, 553074509287335L, "test2")); + timers.add(new Timer(228954L, 1L, 1L, 0L, 553074509287336L, "test3")); LinkedList mergedIntervals = profiler.mergeRewriteTimeIntervals(timers); assertThat(mergedIntervals.size(), equalTo(2)); long[] interval = mergedIntervals.get(0); diff --git a/server/src/test/java/org/opensearch/search/profile/query/ProfileScorerTests.java b/server/src/test/java/org/opensearch/search/profile/query/ProfileScorerTests.java index a4ff92ec556e9..0112fa0839965 100644 --- a/server/src/test/java/org/opensearch/search/profile/query/ProfileScorerTests.java +++ b/server/src/test/java/org/opensearch/search/profile/query/ProfileScorerTests.java @@ -40,6 +40,7 @@ import org.apache.lucene.search.ScoreMode; import org.apache.lucene.search.Scorer; import org.apache.lucene.search.Weight; +import org.opensearch.search.profile.ProfileMetricUtil; import org.opensearch.test.OpenSearchTestCase; import java.io.IOException; @@ -84,7 +85,7 @@ public void testPropagateMinCompetitiveScore() throws IOException { Query query = new MatchAllDocsQuery(); Weight weight = query.createWeight(new IndexSearcher(new MultiReader()), ScoreMode.TOP_SCORES, 1f); FakeScorer fakeScorer = new FakeScorer(weight); - QueryProfileBreakdown profile = new QueryProfileBreakdown(); + QueryProfileBreakdown profile = new QueryProfileBreakdown(ProfileMetricUtil.getDefaultQueryProfileMetrics()); ProfileScorer profileScorer = new ProfileScorer(fakeScorer, profile); profileScorer.setMinCompetitiveScore(0.42f); assertEquals(0.42f, fakeScorer.minCompetitiveScore, 0f); @@ -94,7 +95,7 @@ public void testPropagateMaxScore() throws IOException { Query query = new MatchAllDocsQuery(); Weight weight = query.createWeight(new IndexSearcher(new MultiReader()), ScoreMode.TOP_SCORES, 1f); FakeScorer fakeScorer = new FakeScorer(weight); - QueryProfileBreakdown profile = new QueryProfileBreakdown(); + QueryProfileBreakdown profile = new QueryProfileBreakdown(ProfileMetricUtil.getDefaultQueryProfileMetrics()); ProfileScorer profileScorer = new ProfileScorer(fakeScorer, profile); profileScorer.setMinCompetitiveScore(0.42f); fakeScorer.maxScore = 42f;