Skip to content

Commit 6766e8d

Browse files
authored
Add test for msearch and async search around took time metrics collection (#133396)
1 parent 73c74fb commit 6766e8d

File tree

2 files changed

+212
-17
lines changed

2 files changed

+212
-17
lines changed

server/src/test/java/org/elasticsearch/search/TelemetryMetrics/SearchTookTimeTelemetryTests.java

Lines changed: 57 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -9,27 +9,33 @@
99

1010
package org.elasticsearch.search.TelemetryMetrics;
1111

12+
import org.elasticsearch.action.search.MultiSearchRequestBuilder;
13+
import org.elasticsearch.action.search.MultiSearchResponse;
14+
import org.elasticsearch.action.search.SearchRequest;
15+
import org.elasticsearch.action.search.SearchResponse;
1216
import org.elasticsearch.cluster.metadata.IndexMetadata;
1317
import org.elasticsearch.common.settings.Settings;
1418
import org.elasticsearch.core.TimeValue;
1519
import org.elasticsearch.plugins.Plugin;
1620
import org.elasticsearch.plugins.PluginsService;
21+
import org.elasticsearch.search.builder.SearchSourceBuilder;
1722
import org.elasticsearch.telemetry.Measurement;
1823
import org.elasticsearch.telemetry.TestTelemetryPlugin;
1924
import org.elasticsearch.test.ESSingleNodeTestCase;
20-
import org.hamcrest.MatcherAssert;
2125
import org.junit.After;
2226
import org.junit.Before;
2327

28+
import java.util.Arrays;
2429
import java.util.Collection;
30+
import java.util.Comparator;
2531
import java.util.List;
2632

2733
import static org.elasticsearch.action.support.WriteRequest.RefreshPolicy.IMMEDIATE;
2834
import static org.elasticsearch.index.query.QueryBuilders.simpleQueryStringQuery;
2935
import static org.elasticsearch.rest.action.search.SearchResponseMetrics.TOOK_DURATION_TOTAL_HISTOGRAM_NAME;
36+
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertNoFailures;
3037
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertScrollResponsesAndHitCount;
31-
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchHitsWithoutFailures;
32-
import static org.hamcrest.Matchers.greaterThan;
38+
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchHits;
3339

3440
public class SearchTookTimeTelemetryTests extends ESSingleNodeTestCase {
3541
private static final String indexName = "test_search_metrics2";
@@ -40,7 +46,7 @@ protected boolean resetNodeAfterTest() {
4046
}
4147

4248
@Before
43-
public void setUpIndex() throws Exception {
49+
public void setUpIndex() {
4450
var num_primaries = randomIntBetween(1, 4);
4551
createIndex(
4652
indexName,
@@ -56,7 +62,7 @@ public void setUpIndex() throws Exception {
5662
}
5763

5864
@After
59-
private void afterTest() {
65+
public void afterTest() {
6066
resetMeter();
6167
}
6268

@@ -66,8 +72,48 @@ protected Collection<Class<? extends Plugin>> getPlugins() {
6672
}
6773

6874
public void testSimpleQuery() {
69-
assertSearchHitsWithoutFailures(client().prepareSearch(indexName).setQuery(simpleQueryStringQuery("foo")), "1", "2");
70-
assertMetricsRecorded();
75+
SearchResponse searchResponse = client().prepareSearch(indexName).setQuery(simpleQueryStringQuery("foo")).get();
76+
try {
77+
assertNoFailures(searchResponse);
78+
assertSearchHits(searchResponse, "1", "2");
79+
} finally {
80+
searchResponse.decRef();
81+
}
82+
83+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
84+
assertEquals(1, measurements.size());
85+
assertEquals(searchResponse.getTook().millis(), measurements.getFirst().getLong());
86+
}
87+
88+
public void testMultiSearch() {
89+
MultiSearchRequestBuilder multiSearchRequestBuilder = client().prepareMultiSearch();
90+
int numSearchRequests = randomIntBetween(3, 10);
91+
for (int i = 0; i < numSearchRequests; i++) {
92+
SearchRequest searchRequest = new SearchRequest();
93+
searchRequest.source(new SearchSourceBuilder().query(simpleQueryStringQuery("foo")));
94+
multiSearchRequestBuilder.add(searchRequest);
95+
}
96+
List<Long> tookTimes;
97+
MultiSearchResponse multiSearchResponse = null;
98+
try {
99+
multiSearchResponse = multiSearchRequestBuilder.get();
100+
tookTimes = Arrays.stream(multiSearchResponse.getResponses())
101+
.map(item -> item.getResponse().getTook().millis())
102+
.sorted()
103+
.toList();
104+
} finally {
105+
if (multiSearchResponse != null) {
106+
multiSearchResponse.decRef();
107+
}
108+
}
109+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
110+
assertEquals(numSearchRequests, measurements.size());
111+
measurements.sort(Comparator.comparing(Measurement::getLong));
112+
113+
int i = 0;
114+
for (Measurement measurement : measurements) {
115+
assertEquals(tookTimes.get(i++).longValue(), measurement.getLong());
116+
}
71117
}
72118

73119
public void testScroll() {
@@ -78,26 +124,20 @@ public void testScroll() {
78124
2,
79125
(respNum, response) -> {
80126
if (respNum <= 2) {
81-
assertMetricsRecorded();
127+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(
128+
TOOK_DURATION_TOTAL_HISTOGRAM_NAME
129+
);
130+
assertEquals(1, measurements.size());
82131
}
83132
resetMeter();
84133
}
85134
);
86135
}
87136

88-
private void assertMetricsRecorded() {
89-
MatcherAssert.assertThat(getNumberOfLongHistogramMeasurements(TOOK_DURATION_TOTAL_HISTOGRAM_NAME), greaterThan(0));
90-
}
91-
92137
private void resetMeter() {
93138
getTestTelemetryPlugin().resetMeter();
94139
}
95140

96-
private int getNumberOfLongHistogramMeasurements(String instrumentName) {
97-
final List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(instrumentName);
98-
return measurements.size();
99-
}
100-
101141
private TestTelemetryPlugin getTestTelemetryPlugin() {
102142
return getInstanceFromNode(PluginsService.class).filterPlugins(TestTelemetryPlugin.class).toList().get(0);
103143
}
Lines changed: 155 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,155 @@
1+
/*
2+
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
3+
* or more contributor license agreements. Licensed under the Elastic License
4+
* 2.0; you may not use this file except in compliance with the Elastic License
5+
* 2.0.
6+
*/
7+
8+
package org.elasticsearch.xpack.search;
9+
10+
import org.elasticsearch.action.search.SearchResponse;
11+
import org.elasticsearch.cluster.metadata.IndexMetadata;
12+
import org.elasticsearch.common.settings.Settings;
13+
import org.elasticsearch.core.TimeValue;
14+
import org.elasticsearch.plugins.Plugin;
15+
import org.elasticsearch.plugins.PluginsService;
16+
import org.elasticsearch.search.builder.SearchSourceBuilder;
17+
import org.elasticsearch.telemetry.Measurement;
18+
import org.elasticsearch.telemetry.TestTelemetryPlugin;
19+
import org.elasticsearch.test.ESSingleNodeTestCase;
20+
import org.elasticsearch.xpack.core.async.GetAsyncResultRequest;
21+
import org.elasticsearch.xpack.core.async.GetAsyncStatusRequest;
22+
import org.elasticsearch.xpack.core.search.action.AsyncSearchResponse;
23+
import org.elasticsearch.xpack.core.search.action.AsyncStatusResponse;
24+
import org.elasticsearch.xpack.core.search.action.GetAsyncSearchAction;
25+
import org.elasticsearch.xpack.core.search.action.GetAsyncStatusAction;
26+
import org.elasticsearch.xpack.core.search.action.SubmitAsyncSearchAction;
27+
import org.elasticsearch.xpack.core.search.action.SubmitAsyncSearchRequest;
28+
import org.junit.After;
29+
import org.junit.Before;
30+
31+
import java.util.Collection;
32+
import java.util.List;
33+
34+
import static org.elasticsearch.action.support.WriteRequest.RefreshPolicy.IMMEDIATE;
35+
import static org.elasticsearch.index.query.QueryBuilders.simpleQueryStringQuery;
36+
import static org.elasticsearch.rest.action.search.SearchResponseMetrics.TOOK_DURATION_TOTAL_HISTOGRAM_NAME;
37+
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchHits;
38+
39+
public class AsyncSearchTookTimeTelemetryTests extends ESSingleNodeTestCase {
40+
41+
private static final String indexName = "test_search_metrics2";
42+
43+
@Override
44+
protected boolean resetNodeAfterTest() {
45+
return true;
46+
}
47+
48+
@Before
49+
public void setUpIndex() {
50+
var num_primaries = randomIntBetween(1, 4);
51+
createIndex(
52+
indexName,
53+
Settings.builder()
54+
.put(IndexMetadata.SETTING_NUMBER_OF_SHARDS, num_primaries)
55+
.put(IndexMetadata.SETTING_NUMBER_OF_REPLICAS, 0)
56+
.build()
57+
);
58+
ensureGreen(indexName);
59+
60+
prepareIndex(indexName).setId("1").setSource("body", "foo").setRefreshPolicy(IMMEDIATE).get();
61+
prepareIndex(indexName).setId("2").setSource("body", "foo").setRefreshPolicy(IMMEDIATE).get();
62+
}
63+
64+
@After
65+
public void afterTest() {
66+
getTestTelemetryPlugin().resetMeter();
67+
}
68+
69+
@Override
70+
protected Collection<Class<? extends Plugin>> getPlugins() {
71+
return pluginList(TestTelemetryPlugin.class, AsyncSearch.class);
72+
}
73+
74+
/**
75+
* Test an async search with a wait for completion timeout that is higher than the expected search execution time, that turns into
76+
* a sync request given its execution will always be completed directly as submit async search returns.
77+
*/
78+
public void testAsyncForegroundQuery() {
79+
SubmitAsyncSearchRequest asyncSearchRequest = new SubmitAsyncSearchRequest(
80+
new SearchSourceBuilder().query(simpleQueryStringQuery("foo"))
81+
);
82+
asyncSearchRequest.setWaitForCompletionTimeout(TimeValue.timeValueSeconds(5));
83+
asyncSearchRequest.setKeepOnCompletion(true);
84+
AsyncSearchResponse asyncSearchResponse = client().execute(SubmitAsyncSearchAction.INSTANCE, asyncSearchRequest).actionGet();
85+
String id = asyncSearchResponse.getId();
86+
long tookInMillis;
87+
try {
88+
assertFalse(asyncSearchResponse.isPartial());
89+
assertFalse(asyncSearchResponse.isRunning());
90+
SearchResponse searchResponse = asyncSearchResponse.getSearchResponse();
91+
tookInMillis = searchResponse.getTookInMillis();
92+
assertSearchHits(searchResponse, "1", "2");
93+
} finally {
94+
asyncSearchResponse.decRef();
95+
}
96+
final List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
97+
assertEquals(1, measurements.size());
98+
assertEquals(tookInMillis, measurements.getFirst().getLong());
99+
100+
for (int i = 0; i < randomIntBetween(3, 10); i++) {
101+
AsyncSearchResponse asyncSearchResponse2 = client().execute(GetAsyncSearchAction.INSTANCE, new GetAsyncResultRequest(id))
102+
.actionGet();
103+
try {
104+
assertSearchHits(asyncSearchResponse2.getSearchResponse(), "1", "2");
105+
} finally {
106+
asyncSearchResponse2.decRef();
107+
}
108+
assertEquals(1, measurements.size());
109+
assertEquals(tookInMillis, measurements.getFirst().getLong());
110+
}
111+
}
112+
113+
/**
114+
* Test an async search with a very low wait for completion timeout, which then runs in the background and is not directly completed
115+
* when submit async search returns. Verify that the took time is recorded once, with the actual execution time of the search,
116+
* without any influence from get async search polling happening around the same async search request.
117+
*/
118+
public void testAsyncBackgroundQuery() throws Exception {
119+
SubmitAsyncSearchRequest asyncSearchRequest = new SubmitAsyncSearchRequest(
120+
new SearchSourceBuilder().query(simpleQueryStringQuery("foo"))
121+
);
122+
asyncSearchRequest.setWaitForCompletionTimeout(TimeValue.ZERO);
123+
AsyncSearchResponse asyncSearchResponse = client().execute(SubmitAsyncSearchAction.INSTANCE, asyncSearchRequest).actionGet();
124+
String id;
125+
try {
126+
id = asyncSearchResponse.getId();
127+
} finally {
128+
asyncSearchResponse.decRef();
129+
}
130+
131+
assertBusy(() -> {
132+
AsyncStatusResponse asyncStatusResponse = client().execute(GetAsyncStatusAction.INSTANCE, new GetAsyncStatusRequest(id))
133+
.actionGet();
134+
assertFalse(asyncStatusResponse.isRunning());
135+
});
136+
137+
final List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
138+
for (int i = 0; i < randomIntBetween(3, 10); i++) {
139+
AsyncSearchResponse asyncSearchResponse2 = client().execute(GetAsyncSearchAction.INSTANCE, new GetAsyncResultRequest(id))
140+
.actionGet();
141+
assertEquals(1, measurements.size());
142+
SearchResponse searchResponse = asyncSearchResponse2.getSearchResponse();
143+
try {
144+
assertSearchHits(searchResponse, "1", "2");
145+
assertEquals(searchResponse.getTook().millis(), measurements.getFirst().getLong());
146+
} finally {
147+
asyncSearchResponse2.decRef();
148+
}
149+
}
150+
}
151+
152+
private TestTelemetryPlugin getTestTelemetryPlugin() {
153+
return getInstanceFromNode(PluginsService.class).filterPlugins(TestTelemetryPlugin.class).toList().getFirst();
154+
}
155+
}

0 commit comments

Comments
 (0)