Skip to content

Commit 645cc95

Browse files
committed
Add test for msearch and async search around took time metrics collection
1 parent 6b1560d commit 645cc95

File tree

2 files changed

+191
-14
lines changed

2 files changed

+191
-14
lines changed

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

Lines changed: 43 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -9,11 +9,17 @@
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.SearchRequestBuilder;
16+
import org.elasticsearch.action.search.SearchResponse;
1217
import org.elasticsearch.cluster.metadata.IndexMetadata;
1318
import org.elasticsearch.common.settings.Settings;
1419
import org.elasticsearch.core.TimeValue;
1520
import org.elasticsearch.plugins.Plugin;
1621
import org.elasticsearch.plugins.PluginsService;
22+
import org.elasticsearch.search.builder.SearchSourceBuilder;
1723
import org.elasticsearch.telemetry.Measurement;
1824
import org.elasticsearch.telemetry.TestTelemetryPlugin;
1925
import org.elasticsearch.test.ESSingleNodeTestCase;
@@ -27,7 +33,9 @@
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;
38+
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchHits;
3139
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchHitsWithoutFailures;
3240
import static org.hamcrest.Matchers.greaterThan;
3341

@@ -40,7 +48,7 @@ protected boolean resetNodeAfterTest() {
4048
}
4149

4250
@Before
43-
public void setUpIndex() throws Exception {
51+
public void setUpIndex() {
4452
var num_primaries = randomIntBetween(1, 4);
4553
createIndex(
4654
indexName,
@@ -56,7 +64,7 @@ public void setUpIndex() throws Exception {
5664
}
5765

5866
@After
59-
private void afterTest() {
67+
public void afterTest() {
6068
resetMeter();
6169
}
6270

@@ -66,8 +74,37 @@ protected Collection<Class<? extends Plugin>> getPlugins() {
6674
}
6775

6876
public void testSimpleQuery() {
69-
assertSearchHitsWithoutFailures(client().prepareSearch(indexName).setQuery(simpleQueryStringQuery("foo")), "1", "2");
70-
assertMetricsRecorded();
77+
SearchResponse searchResponse = client().prepareSearch(indexName).setQuery(simpleQueryStringQuery("foo")).get();
78+
try {
79+
assertNoFailures(searchResponse);
80+
assertSearchHits(searchResponse, "1", "2");
81+
} finally {
82+
searchResponse.decRef();
83+
}
84+
85+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
86+
assertEquals(1, measurements.size());
87+
assertEquals(searchResponse.getTook().millis(), measurements.getFirst().getLong());
88+
}
89+
90+
public void testMultiSearch() {
91+
MultiSearchRequestBuilder multiSearchRequestBuilder = client().prepareMultiSearch();
92+
int numSearchRequests = randomIntBetween(3, 10);
93+
for (int i = 0; i < numSearchRequests; i++) {
94+
SearchRequest searchRequest = new SearchRequest();
95+
searchRequest.source(new SearchSourceBuilder().query(simpleQueryStringQuery("foo")));
96+
multiSearchRequestBuilder.add(searchRequest);
97+
}
98+
MultiSearchResponse multiSearchResponse = null;
99+
try {
100+
multiSearchResponse = multiSearchRequestBuilder.get();
101+
} finally {
102+
if (multiSearchResponse != null) {
103+
multiSearchResponse.decRef();
104+
}
105+
}
106+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
107+
assertEquals(numSearchRequests, measurements.size());
71108
}
72109

73110
public void testScroll() {
@@ -78,26 +115,18 @@ public void testScroll() {
78115
2,
79116
(respNum, response) -> {
80117
if (respNum <= 2) {
81-
assertMetricsRecorded();
118+
List<Measurement> measurements = getTestTelemetryPlugin().getLongHistogramMeasurement(TOOK_DURATION_TOTAL_HISTOGRAM_NAME);
119+
assertEquals(1, measurements.size());
82120
}
83121
resetMeter();
84122
}
85123
);
86124
}
87125

88-
private void assertMetricsRecorded() {
89-
MatcherAssert.assertThat(getNumberOfLongHistogramMeasurements(TOOK_DURATION_TOTAL_HISTOGRAM_NAME), greaterThan(0));
90-
}
91-
92126
private void resetMeter() {
93127
getTestTelemetryPlugin().resetMeter();
94128
}
95129

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

0 commit comments

Comments
 (0)