Skip to content

Commit aa1c662

Browse files
authored
Fix SearchStatsContributor to report per-shard fragment counts (opensearch-project#22291)
The analytics-engine SearchStatsContributor was reporting 1-per-query (via queries.elapsed_ms.count), but Lucene's ShardSearchStats counts 1-per-shard via per-shard onPreQueryPhase / onQueryPhase callbacks. Downstream consumers of _nodes/stats search counters were undercounting analytics-engine traffic by the shard fan-out factor (e.g. ~50x on a 50-shard index, ~8x on 8 shards). A secondary symptom: query_time_in_millis was reporting near-zero because AnalyticsStatsCollector.recordExecution computes per-query elapsed as (latestStageEnd - earliestStageStart) and skips recording when either timestamp is 0, dropping most queries' latency entirely. Fix: contribute from the fragments bucket (per-shard StageTasks) instead of the per-query bucket. fragments.total is populated once per shard execution with its own elapsed time, matching Lucene's per-shard semantics for both count and time-in-millis. Empirical confirmation on a 27-node OpenSearch 3.5 cluster: 50 PPL queries against a 50-shard index - Observed: cluster-wide query_total delta = 36 - Expected (Lucene parity): 50 queries x 50 shards = 2500 - Per-node breakdown: only 3 of 27 nodes incremented (coordinators) 100 PPL queries against an 8-shard index - Observed: cluster-wide query_total delta = 66 - Expected (Lucene parity): 100 queries x 8 shards = 800 The ratio of undercount scales with shard count, exactly as shard-fan-out-vs-1-per-query predicts. Also splits SearchStatsContributorIT into three tests: - testQueryTotalScalesWithShardFanOut: 3-shard index, asserts delta >= N*shards/2 (catches the 1-per-query bug) - testQueryTimeIncrementsAfterAnalyticsQueries: asserts time delta > 0 (catches the all-or-nothing-window latency bug) - testQueryTotalIncrementsAtLeastOncePerQuery: asserts delta >= N (catches a regression where the contributor stops firing) Signed-off-by: Michael Oviedo <mikeovi@amazon.com>
1 parent 64d6b50 commit aa1c662

2 files changed

Lines changed: 87 additions & 23 deletions

File tree

sandbox/plugins/analytics-engine/src/main/java/org/opensearch/analytics/AnalyticsPlugin.java

Lines changed: 18 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -260,11 +260,26 @@ static int schedulerPoolSize() {
260260

261261
@Override
262262
public SearchStats contributeSearchStats() {
263-
AnalyticsStats.LatencyStats elapsed = statsCollector.snapshot().queries().elapsedMs();
264-
if (elapsed.count() == 0) {
263+
// Contribute per-shard fragment task counts so the node-level search counters
264+
// exposed via _nodes/stats match Lucene's per-shard accounting (one increment
265+
// per shard query phase, not per user query).
266+
//
267+
// The queries.elapsed_ms bucket counts 1-per-query, which undercounts the
268+
// rate by the shard fan-out factor and drops most queries' latency (the
269+
// start/end window in AnalyticsStatsCollector#recordExecution is commonly
270+
// 0 when stage timestamps aren't populated). The SHARD_FRAGMENT stage
271+
// bucket counts 1-per-(query, node-hosting-shards), still missing the
272+
// per-shard granularity Lucene reports. fragments.total walks each
273+
// SHARD_FRAGMENT execution's per-shard StageTasks, giving per-shard
274+
// counts matching Lucene's onPreQueryPhase semantics.
275+
AnalyticsStats snapshot = statsCollector.snapshot();
276+
AnalyticsStats.Fragments fragments = snapshot.fragments();
277+
if (fragments == null || fragments.total() == 0) {
265278
return null;
266279
}
267-
SearchStats.Stats stats = new SearchStats.Stats.Builder().queryCount(elapsed.count()).queryTimeInMillis(elapsed.sumMs()).build();
280+
SearchStats.Stats stats = new SearchStats.Stats.Builder().queryCount(fragments.total())
281+
.queryTimeInMillis(fragments.elapsedMs().sumMs())
282+
.build();
268283
return new SearchStats(stats, 0, null);
269284
}
270285

sandbox/qa/analytics-engine-rest/src/test/java/org/opensearch/analytics/qa/SearchStatsContributorIT.java

Lines changed: 69 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -25,42 +25,91 @@
2525
public class SearchStatsContributorIT extends AnalyticsRestTestCase {
2626

2727
private static final Dataset DATASET = new Dataset("calcs", "calcs");
28+
/**
29+
* Multi-shard index so the test can distinguish the per-query contributor
30+
* (queryCount delta ≈ N) from the per-shard Lucene-equivalent contributor
31+
* (queryCount delta ≈ N × shards). Catches the regression class where the
32+
* contributor counts 1-per-query and silently under-reports search rate
33+
* by the shard fan-out factor to downstream consumers of node stats.
34+
*/
35+
private static final int NUMBER_OF_SHARDS = 3;
2836
private static boolean dataProvisioned = false;
2937

3038
private void ensureDataProvisioned() throws IOException {
3139
if (dataProvisioned == false) {
32-
DatasetProvisioner.provision(client(), DATASET);
40+
DatasetProvisioner.provision(client(), DATASET, NUMBER_OF_SHARDS);
3341
dataProvisioned = true;
3442
}
3543
}
3644

37-
public void testQueryTotalIncrementsAfterAnalyticsQueries() throws IOException {
45+
/**
46+
* Guards the 1-per-query bug: cluster-wide query_total must grow with the
47+
* shard fan-out factor. A 1-per-query contributor would produce delta ≈ N
48+
* (instead of N × shards), under-reporting search rate by the shard fan-out
49+
* factor to downstream consumers of node stats.
50+
*/
51+
public void testQueryTotalScalesWithShardFanOut() throws IOException {
3852
ensureDataProvisioned();
3953

40-
long baselineQueryTotal = getQueryTotalAcrossNodes();
41-
long baselineQueryTimeMs = getQueryTimeAcrossNodes();
54+
long before = getQueryTotalAcrossNodes();
55+
fireQueries();
56+
long after = getQueryTotalAcrossNodes();
4257

43-
// Fire a handful of analytics-engine PPL queries — varied shapes so the contributor
44-
// sees both real elapsed time and a non-trivial count.
58+
long delta = after - before;
59+
long minExpected = (long) TOTAL_QUERIES * NUMBER_OF_SHARDS / 2;
60+
assertTrue(
61+
"search.query_total must grow with shard fan-out (fired " + TOTAL_QUERIES
62+
+ " on " + NUMBER_OF_SHARDS + "-shard index, expected ≥ " + minExpected
63+
+ ", observed delta=" + delta + ")",
64+
delta >= minExpected
65+
);
66+
}
67+
68+
/**
69+
* Guards the latency-aggregation bug: query_time_in_millis must move when
70+
* real PPL work runs. A delta of 0 means the contributor's time source
71+
* dropped every recording (e.g. an all-or-nothing window that collapsed).
72+
*/
73+
public void testQueryTimeIncrementsAfterAnalyticsQueries() throws IOException {
74+
ensureDataProvisioned();
75+
76+
long before = getQueryTimeAcrossNodes();
77+
fireQueries();
78+
long after = getQueryTimeAcrossNodes();
79+
80+
long delta = after - before;
81+
assertTrue("search.query_time_in_millis must grow > 0 after PPL work, observed delta=" + delta, delta > 0);
82+
}
83+
84+
/**
85+
* Minimum-viable check: every fired query must contribute at least once to
86+
* cluster-wide query_total. Catches regressions where the contributor stops
87+
* firing entirely (e.g. returns null, or filters out all stages).
88+
*/
89+
public void testQueryTotalIncrementsAtLeastOncePerQuery() throws IOException {
90+
ensureDataProvisioned();
91+
92+
long before = getQueryTotalAcrossNodes();
93+
fireQueries();
94+
long after = getQueryTotalAcrossNodes();
95+
96+
long delta = after - before;
97+
assertTrue(
98+
"search.query_total must grow by at least one per query (fired " + TOTAL_QUERIES
99+
+ ", observed delta=" + delta + ")",
100+
delta >= TOTAL_QUERIES
101+
);
102+
}
103+
104+
private static final int TOTAL_QUERIES = 15;
105+
106+
private void fireQueries() throws IOException {
107+
// Varied shapes so the contributor sees both real elapsed time and a non-trivial count.
45108
for (int i = 0; i < 5; i++) {
46109
executePpl("source=" + DATASET.indexName + " | fields str0");
47110
executePpl("source=" + DATASET.indexName + " | where num0 > 0 | fields str0, num0");
48111
executePpl("source=" + DATASET.indexName + " | stats avg(num0)");
49112
}
50-
51-
long afterQueryTotal = getQueryTotalAcrossNodes();
52-
long afterQueryTimeMs = getQueryTimeAcrossNodes();
53-
54-
long countDelta = afterQueryTotal - baselineQueryTotal;
55-
assertTrue(
56-
"search.query_total must increment by at least 1 after analytics queries, delta=" + countDelta,
57-
countDelta >= 1
58-
);
59-
// query_time_in_millis is a sum so it should grow strictly monotonically with count;
60-
// any single query that took 0ms is unlikely with non-trivial work, but the contract
61-
// we care about is "the field is being populated", so >= 0 is enough.
62-
long timeDelta = afterQueryTimeMs - baselineQueryTimeMs;
63-
assertTrue("search.query_time_in_millis must not regress, delta=" + timeDelta, timeDelta >= 0);
64113
}
65114

66115
private long getQueryTotalAcrossNodes() throws IOException {

0 commit comments

Comments
 (0)