Skip to content

Commit afe97af

Browse files
nik9000nik9000
authored
ESQL: Count took times (#126547)
Build a little histogram of the `took` times of ESQL queries in a cluster. Graphing this can tell you how much ESQL is in use. Especially for heavy or light things.
1 parent 75f54a4 commit afe97af

File tree

8 files changed

+202
-23
lines changed

8 files changed

+202
-23
lines changed

‎x-pack/plugin/esql/qa/server/multi-clusters/src/javaRestTest/java/org/elasticsearch/xpack/esql/ccq/MultiClusterSpecIT.java‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -302,4 +302,10 @@ protected boolean supportsIndexModeLookup() throws IOException {
302302
protected boolean supportsSourceFieldMapping() {
303303
return false;
304304
}
305+
306+
@Override
307+
protected boolean supportsTook() throws IOException {
308+
// We don't read took properly in multi-cluster tests.
309+
return false;
310+
}
305311
}

‎x-pack/plugin/esql/qa/server/src/main/java/org/elasticsearch/xpack/esql/qa/rest/EsqlSpecTestCase.java‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@
3333
import org.elasticsearch.xpack.esql.SpecReader;
3434
import org.elasticsearch.xpack.esql.plugin.EsqlFeatures;
3535
import org.elasticsearch.xpack.esql.qa.rest.RestEsqlTestCase.RequestObjectBuilder;
36+
import org.elasticsearch.xpack.esql.telemetry.TookMetrics;
3637
import org.junit.After;
3738
import org.junit.AfterClass;
3839
import org.junit.Before;
@@ -91,6 +92,7 @@ public abstract class EsqlSpecTestCase extends ESRestTestCase {
9192
protected final CsvTestCase testCase;
9293
protected final String instructions;
9394
protected final Mode mode;
95+
protected static Boolean supportsTook;
9496

9597
public enum Mode {
9698
SYNC,
@@ -271,6 +273,7 @@ protected final void doTest() throws Throwable {
271273
builder.tables(tables());
272274
}
273275

276+
Map<?, ?> prevTooks = supportsTook() ? tooks() : null;
274277
Map<String, Object> answer = runEsql(builder.query(testCase.query), testCase.assertWarnings(deduplicateExactWarnings()));
275278

276279
var expectedColumnsWithValues = loadCsvSpecValues(testCase.expectedResults);
@@ -287,6 +290,21 @@ protected final void doTest() throws Throwable {
287290
List<List<Object>> actualValues = (List<List<Object>>) values;
288291

289292
assertResults(expectedColumnsWithValues, actualColumns, actualValues, testCase.ignoreOrder, logger);
293+
294+
if (supportsTook()) {
295+
LOGGER.info("checking took incremented from {}", prevTooks);
296+
long took = ((Number) answer.get("took")).longValue();
297+
int prevTookHisto = ((Number) prevTooks.remove(tookKey(took))).intValue();
298+
assertMap(tooks(), matchesMap(prevTooks).entry(tookKey(took), prevTookHisto + 1));
299+
}
300+
}
301+
302+
private Map<?, ?> tooks() throws IOException {
303+
Request request = new Request("GET", "/_xpack/usage");
304+
HttpEntity entity = client().performRequest(request).getEntity();
305+
Map<?, ?> usage = XContentHelper.convertToMap(XContentType.JSON.xContent(), entity.getContent(), false);
306+
Map<?, ?> esql = (Map<?, ?>) usage.get("esql");
307+
return (Map<?, ?>) esql.get("took");
290308
}
291309

292310
/**
@@ -471,4 +489,36 @@ private Map<String, Map<String, RestEsqlTestCase.TypeAndValues>> tables() {
471489
);
472490
return tables;
473491
}
492+
493+
protected boolean supportsTook() throws IOException {
494+
if (supportsTook == null) {
495+
supportsTook = hasCapabilities(client(), List.of("usage_contains_took"));
496+
}
497+
return supportsTook;
498+
}
499+
500+
private String tookKey(long took) {
501+
if (took < 10) {
502+
return "lt_10ms";
503+
}
504+
if (took < 100) {
505+
return "lt_100ms";
506+
}
507+
if (took < TookMetrics.ONE_SECOND) {
508+
return "lt_1s";
509+
}
510+
if (took < TookMetrics.TEN_SECONDS) {
511+
return "lt_10s";
512+
}
513+
if (took < TookMetrics.ONE_MINUTE) {
514+
return "lt_1m";
515+
}
516+
if (took < TookMetrics.TEN_MINUTES) {
517+
return "lt_10m";
518+
}
519+
if (took < TookMetrics.ONE_DAY) {
520+
return "lt_1d";
521+
}
522+
return "gt_1d";
523+
}
474524
}

‎x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/action/EsqlCapabilities.java‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -969,7 +969,12 @@ public enum Cap {
969969
/**
970970
* Support STATS/EVAL/DISSECT in Fork branches
971971
*/
972-
FORK_V2(Build.current().isSnapshot());
972+
FORK_V2(Build.current().isSnapshot()),
973+
974+
/**
975+
* Does the usage information for ESQL contain a histogram of {@code took} values?
976+
*/
977+
USAGE_CONTAINS_TOOK;
973978

974979
private final boolean enabled;
975980

‎x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/plugin/TransportEsqlQueryAction.java‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -246,6 +246,7 @@ private void innerExecute(Task task, EsqlQueryRequest request, ActionListener<Es
246246
services,
247247
ActionListener.wrap(result -> {
248248
recordCCSTelemetry(task, executionInfo, request, null);
249+
planExecutor.metrics().recordTook(executionInfo.overallTook().millis());
249250
listener.onResponse(toResponse(task, request, configuration, result));
250251
}, ex -> {
251252
recordCCSTelemetry(task, executionInfo, request, ex);

‎x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/telemetry/Metrics.java‎

Lines changed: 15 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -35,14 +35,17 @@ public String toString() {
3535
}
3636
}
3737

38+
protected static final String QUERIES_PREFIX = "queries.";
39+
protected static final String FEATURES_PREFIX = "features.";
40+
protected static final String FUNC_PREFIX = "functions.";
41+
protected static final String TOOK_PREFIX = "took.";
42+
3843
// map that holds total/failed counters for each client type (rest, kibana)
3944
private final Map<QueryMetric, Map<OperationType, CounterMetric>> opsByTypeMetrics;
4045
// map that holds one counter per esql query "feature" (eval, sort, limit, where....)
4146
private final Map<FeatureMetric, CounterMetric> featuresMetrics;
4247
private final Map<String, CounterMetric> functionMetrics;
43-
protected static String QPREFIX = "queries.";
44-
protected static String FPREFIX = "features.";
45-
protected static String FUNC_PREFIX = "functions.";
48+
private final TookMetrics tookMetrics = new TookMetrics();
4649

4750
private final EsqlFunctionRegistry functionRegistry;
4851
private final Map<Class<?>, String> classToFunctionName;
@@ -118,6 +121,10 @@ public void incFunctionMetric(Class<?> functionType) {
118121
}
119122
}
120123

124+
public void recordTook(long tookMillis) {
125+
tookMetrics.count(tookMillis);
126+
}
127+
121128
public Counters stats() {
122129
Counters counters = new Counters();
123130

@@ -129,21 +136,23 @@ public Counters stats() {
129136
long metricCounter = entry.getValue().get(type).count();
130137
String operationTypeName = type.toString();
131138

132-
counters.inc(QPREFIX + metricName + "." + operationTypeName, metricCounter);
133-
counters.inc(QPREFIX + "_all." + operationTypeName, metricCounter);
139+
counters.inc(QUERIES_PREFIX + metricName + "." + operationTypeName, metricCounter);
140+
counters.inc(QUERIES_PREFIX + "_all." + operationTypeName, metricCounter);
134141
}
135142
}
136143

137144
// features metrics
138145
for (Entry<FeatureMetric, CounterMetric> entry : featuresMetrics.entrySet()) {
139-
counters.inc(FPREFIX + entry.getKey().toString(), entry.getValue().count());
146+
counters.inc(FEATURES_PREFIX + entry.getKey().toString(), entry.getValue().count());
140147
}
141148

142149
// function metrics
143150
for (Entry<String, CounterMetric> entry : functionMetrics.entrySet()) {
144151
counters.inc(FUNC_PREFIX + entry.getKey(), entry.getValue().count());
145152
}
146153

154+
tookMetrics.counters(TOOK_PREFIX, counters);
155+
147156
return counters;
148157
}
149158
}

‎x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/telemetry/TookMetrics.java‎

Lines changed: 86 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,86 @@
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.esql.telemetry;
9+
10+
import org.elasticsearch.common.metrics.CounterMetric;
11+
import org.elasticsearch.core.TimeValue;
12+
import org.elasticsearch.xpack.core.watcher.common.stats.Counters;
13+
14+
public class TookMetrics {
15+
public static final long ONE_SECOND = TimeValue.timeValueSeconds(1).millis();
16+
public static final long TEN_SECONDS = TimeValue.timeValueSeconds(10).millis();
17+
public static final long ONE_MINUTE = TimeValue.timeValueMinutes(1).millis();
18+
public static final long TEN_MINUTES = TimeValue.timeValueMinutes(10).millis();
19+
public static final long ONE_HOUR = TimeValue.timeValueHours(1).millis();
20+
public static final long TEN_HOURS = TimeValue.timeValueHours(10).millis();
21+
public static final long ONE_DAY = TimeValue.timeValueDays(1).millis();
22+
23+
private final CounterMetric lessThan10ms = new CounterMetric();
24+
private final CounterMetric lessThan100ms = new CounterMetric();
25+
private final CounterMetric lessThan1s = new CounterMetric();
26+
private final CounterMetric lessThan10s = new CounterMetric();
27+
private final CounterMetric lessThan1m = new CounterMetric();
28+
private final CounterMetric lessThan10m = new CounterMetric();
29+
private final CounterMetric lessThan1h = new CounterMetric();
30+
private final CounterMetric lessThan10h = new CounterMetric();
31+
private final CounterMetric lessThan1d = new CounterMetric();
32+
private final CounterMetric greaterThan1d = new CounterMetric();
33+
34+
public void count(long tookMillis) {
35+
if (tookMillis < 10) {
36+
lessThan10ms.inc();
37+
return;
38+
}
39+
if (tookMillis < 100) {
40+
lessThan100ms.inc();
41+
return;
42+
}
43+
if (tookMillis < ONE_SECOND) {
44+
lessThan1s.inc();
45+
return;
46+
}
47+
if (tookMillis < TEN_SECONDS) {
48+
lessThan10s.inc();
49+
return;
50+
}
51+
if (tookMillis < ONE_MINUTE) {
52+
lessThan1m.inc();
53+
return;
54+
}
55+
if (tookMillis < TEN_MINUTES) {
56+
lessThan10m.inc();
57+
return;
58+
}
59+
if (tookMillis < ONE_HOUR) {
60+
lessThan1h.inc();
61+
return;
62+
}
63+
if (tookMillis < TEN_HOURS) {
64+
lessThan10h.inc();
65+
return;
66+
}
67+
if (tookMillis < ONE_DAY) {
68+
lessThan1d.inc();
69+
return;
70+
}
71+
greaterThan1d.inc();
72+
}
73+
74+
public void counters(String prefix, Counters counters) {
75+
counters.inc(prefix + "lt_10ms", lessThan10ms.count());
76+
counters.inc(prefix + "lt_100ms", lessThan100ms.count());
77+
counters.inc(prefix + "lt_1s", lessThan1s.count());
78+
counters.inc(prefix + "lt_10s", lessThan10s.count());
79+
counters.inc(prefix + "lt_1m", lessThan1m.count());
80+
counters.inc(prefix + "lt_10m", lessThan10m.count());
81+
counters.inc(prefix + "lt_1h", lessThan1h.count());
82+
counters.inc(prefix + "lt_10h", lessThan1h.count());
83+
counters.inc(prefix + "lt_1d", lessThan1d.count());
84+
counters.inc(prefix + "gt_1d", greaterThan1d.count());
85+
}
86+
}

‎x-pack/plugin/esql/src/test/java/org/elasticsearch/xpack/esql/telemetry/VerifierMetricsTests.java‎

Lines changed: 16 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -37,7 +37,7 @@
3737
import static org.elasticsearch.xpack.esql.telemetry.FeatureMetric.SORT;
3838
import static org.elasticsearch.xpack.esql.telemetry.FeatureMetric.STATS;
3939
import static org.elasticsearch.xpack.esql.telemetry.FeatureMetric.WHERE;
40-
import static org.elasticsearch.xpack.esql.telemetry.Metrics.FPREFIX;
40+
import static org.elasticsearch.xpack.esql.telemetry.Metrics.FEATURES_PREFIX;
4141
import static org.elasticsearch.xpack.esql.telemetry.Metrics.FUNC_PREFIX;
4242

4343
public class VerifierMetricsTests extends ESTestCase {
@@ -467,63 +467,63 @@ public void testCategorize() {
467467
}
468468

469469
private long dissect(Counters c) {
470-
return c.get(FPREFIX + DISSECT);
470+
return c.get(FEATURES_PREFIX + DISSECT);
471471
}
472472

473473
private long eval(Counters c) {
474-
return c.get(FPREFIX + EVAL);
474+
return c.get(FEATURES_PREFIX + EVAL);
475475
}
476476

477477
private long grok(Counters c) {
478-
return c.get(FPREFIX + GROK);
478+
return c.get(FEATURES_PREFIX + GROK);
479479
}
480480

481481
private long limit(Counters c) {
482-
return c.get(FPREFIX + LIMIT);
482+
return c.get(FEATURES_PREFIX + LIMIT);
483483
}
484484

485485
private long sort(Counters c) {
486-
return c.get(FPREFIX + SORT);
486+
return c.get(FEATURES_PREFIX + SORT);
487487
}
488488

489489
private long stats(Counters c) {
490-
return c.get(FPREFIX + STATS);
490+
return c.get(FEATURES_PREFIX + STATS);
491491
}
492492

493493
private long where(Counters c) {
494-
return c.get(FPREFIX + WHERE);
494+
return c.get(FEATURES_PREFIX + WHERE);
495495
}
496496

497497
private long enrich(Counters c) {
498-
return c.get(FPREFIX + ENRICH);
498+
return c.get(FEATURES_PREFIX + ENRICH);
499499
}
500500

501501
private long mvExpand(Counters c) {
502-
return c.get(FPREFIX + MV_EXPAND);
502+
return c.get(FEATURES_PREFIX + MV_EXPAND);
503503
}
504504

505505
private long show(Counters c) {
506-
return c.get(FPREFIX + SHOW);
506+
return c.get(FEATURES_PREFIX + SHOW);
507507
}
508508

509509
private long row(Counters c) {
510-
return c.get(FPREFIX + ROW);
510+
return c.get(FEATURES_PREFIX + ROW);
511511
}
512512

513513
private long from(Counters c) {
514-
return c.get(FPREFIX + FROM);
514+
return c.get(FEATURES_PREFIX + FROM);
515515
}
516516

517517
private long drop(Counters c) {
518-
return c.get(FPREFIX + DROP);
518+
return c.get(FEATURES_PREFIX + DROP);
519519
}
520520

521521
private long keep(Counters c) {
522-
return c.get(FPREFIX + KEEP);
522+
return c.get(FEATURES_PREFIX + KEEP);
523523
}
524524

525525
private long rename(Counters c) {
526-
return c.get(FPREFIX + RENAME);
526+
return c.get(FEATURES_PREFIX + RENAME);
527527
}
528528

529529
private long function(String function, Counters c) {

‎x-pack/plugin/src/yamlRestTest/resources/rest-api-spec/test/esql/60_usage.yml‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -179,3 +179,25 @@ setup:
179179
- match: {esql.functions.coalesce: $functions_coalesce}
180180
- gt: {esql.functions.categorize: $functions_categorize}
181181
- length: {esql.functions: 131} # check the "sister" test above for a likely update to the same esql.functions length check
182+
183+
---
184+
took:
185+
- requires:
186+
test_runner_features: [capabilities]
187+
capabilities:
188+
- method: POST
189+
path: /_query
190+
parameters: []
191+
capabilities: [usage_contains_took]
192+
reason: "Test that should only be executed on snapshot versions"
193+
194+
- do: {xpack.usage: {}}
195+
- exists: esql.took.lt_10ms
196+
- exists: esql.took.lt_1s
197+
- exists: esql.took.lt_10s
198+
- exists: esql.took.lt_1m
199+
- exists: esql.took.lt_10m
200+
- exists: esql.took.lt_1h
201+
- exists: esql.took.lt_10h
202+
- exists: esql.took.lt_1d
203+
- exists: esql.took.gt_1d

0 commit comments

Comments
 (0)