Skip to content

Commit cbfcf2c

Browse files
luigidellaquilaluigidellaquila
committed
Add unit tests
1 parent 2eb589a commit cbfcf2c

File tree

2 files changed

+210
-0
lines changed

2 files changed

+210
-0
lines changed

‎x-pack/plugin/esql/src/test/java/org/elasticsearch/xpack/esql/slowlog/EsqlSlowLogTests.java‎

Lines changed: 170 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,170 @@
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.slowlog;
9+
10+
import org.apache.logging.log4j.Level;
11+
import org.apache.logging.log4j.LogManager;
12+
import org.apache.logging.log4j.Logger;
13+
import org.elasticsearch.common.ValidationException;
14+
import org.elasticsearch.common.logging.ESLogMessage;
15+
import org.elasticsearch.common.logging.Loggers;
16+
import org.elasticsearch.common.settings.ClusterSettings;
17+
import org.elasticsearch.common.settings.Settings;
18+
import org.elasticsearch.core.TimeValue;
19+
import org.elasticsearch.test.ESTestCase;
20+
import org.elasticsearch.xpack.esql.action.EsqlExecutionInfo;
21+
import org.elasticsearch.xpack.esql.plugin.EsqlPlugin;
22+
import org.elasticsearch.xpack.esql.session.Result;
23+
import org.junit.AfterClass;
24+
import org.junit.BeforeClass;
25+
26+
import java.util.Arrays;
27+
import java.util.HashSet;
28+
import java.util.List;
29+
import java.util.concurrent.TimeUnit;
30+
31+
import static org.hamcrest.Matchers.equalTo;
32+
import static org.hamcrest.Matchers.greaterThan;
33+
import static org.hamcrest.Matchers.is;
34+
import static org.hamcrest.Matchers.not;
35+
import static org.hamcrest.Matchers.nullValue;
36+
37+
public class EsqlSlowLogTests extends ESTestCase {
38+
private static ClusterSettings settings = new ClusterSettings(
39+
Settings.builder()
40+
.put(EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_WARN_SETTING.getKey(), "40ms")
41+
.put(EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_INFO_SETTING.getKey(), "30ms")
42+
.put(EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_DEBUG_SETTING.getKey(), "20ms")
43+
.put(EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_TRACE_SETTING.getKey(), "10ms")
44+
45+
.build(),
46+
new HashSet<>(
47+
Arrays.asList(
48+
EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_WARN_SETTING,
49+
EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_INFO_SETTING,
50+
EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_DEBUG_SETTING,
51+
EsqlPlugin.ESQL_SLOWLOG_THRESHOLD_QUERY_TRACE_SETTING
52+
)
53+
)
54+
);
55+
56+
static MockAppender appender;
57+
static Logger queryLog = LogManager.getLogger(EsqlSlowLog.SLOWLOG_PREFIX + ".query");
58+
static Level origQueryLogLevel = queryLog.getLevel();
59+
60+
@BeforeClass
61+
public static void init() throws IllegalAccessException {
62+
appender = new MockAppender("test_appender");
63+
appender.start();
64+
Loggers.addAppender(queryLog, appender);
65+
66+
Loggers.setLevel(queryLog, Level.TRACE);
67+
}
68+
69+
@AfterClass
70+
public static void cleanup() {
71+
Loggers.removeAppender(queryLog, appender);
72+
appender.stop();
73+
Loggers.setLevel(queryLog, origQueryLogLevel);
74+
}
75+
76+
public void testPrioritiesOnSuccess() {
77+
EsqlSlowLog slowLog = new EsqlSlowLog(settings);
78+
String query = "from " + randomAlphaOfLength(10);
79+
80+
long[] actualTook = {
81+
randomLongBetween(10_000_000, 20_000_000),
82+
randomLongBetween(20_000_000, 30_000_000),
83+
randomLongBetween(30_000_000, 40_000_000),
84+
randomLongBetween(40_000_000, 50_000_000),
85+
randomLongBetween(0, 9_999_999) };
86+
long[] actualPlanningTook = {
87+
randomLongBetween(0, 1_000_000),
88+
randomLongBetween(0, 1_000_000),
89+
randomLongBetween(0, 1_000_000),
90+
randomLongBetween(0, 1_000_000),
91+
randomLongBetween(0, 1_000_000), };
92+
Level[] expectedLevel = { Level.TRACE, Level.DEBUG, Level.INFO, Level.WARN, null };
93+
94+
for (int i = 0; i < actualTook.length; i++) {
95+
EsqlExecutionInfo warnQuery = getEsqlExecutionInfo(actualTook[i], actualPlanningTook[i]);
96+
slowLog.onQueryPhase(new Result(List.of(), List.of(), List.of(), warnQuery), query);
97+
if (expectedLevel[i] != null) {
98+
assertThat(appender.lastEvent(), is(not(nullValue())));
99+
var msg = (ESLogMessage) appender.lastMessage();
100+
long took = Long.valueOf(msg.get("elasticsearch.slowlog.took"));
101+
long tookMillisExpected = took / 1_000_000L;
102+
long tookMillis = Long.valueOf(msg.get("elasticsearch.slowlog.took_millis"));
103+
assertThat(took, is(actualTook[i]));
104+
assertThat(tookMillis, is(tookMillisExpected));
105+
106+
long planningTook = Long.valueOf(msg.get("elasticsearch.slowlog.planning.took"));
107+
long planningTookMillisExpected = planningTook / 1_000_000;
108+
long planningTookMillis = Long.valueOf(msg.get("elasticsearch.slowlog.planning.took_millis"));
109+
assertThat(planningTook, is(actualPlanningTook[i]));
110+
assertThat(planningTookMillis, is(planningTookMillisExpected));
111+
assertThat(took, greaterThan(planningTook));
112+
assertThat(msg.get("elasticsearch.slowlog.query"), is(query));
113+
assertThat(appender.getLastEventAndReset().getLevel(), equalTo(expectedLevel[i]));
114+
} else {
115+
assertThat(appender.lastEvent(), is(nullValue()));
116+
}
117+
118+
}
119+
}
120+
121+
public void testPrioritiesOnFailure() {
122+
EsqlSlowLog slowLog = new EsqlSlowLog(settings);
123+
String query = "from " + randomAlphaOfLength(10);
124+
125+
long[] actualTook = {
126+
randomLongBetween(10_000_000, 20_000_000),
127+
randomLongBetween(20_000_000, 30_000_000),
128+
randomLongBetween(30_000_000, 40_000_000),
129+
randomLongBetween(40_000_000, 50_000_000),
130+
randomLongBetween(0, 9_999_999) };
131+
132+
Level[] expectedLevel = { Level.TRACE, Level.DEBUG, Level.INFO, Level.WARN, null };
133+
134+
String validationError = randomAlphaOfLength(10);
135+
ValidationException ex = new ValidationException().addValidationError(validationError);
136+
for (int i = 0; i < actualTook.length; i++) {
137+
slowLog.onQueryFailure(query, ex, actualTook[i]);
138+
if (expectedLevel[i] != null) {
139+
assertThat(appender.lastEvent(), is(not(nullValue())));
140+
var msg = (ESLogMessage) appender.lastMessage();
141+
long took = Long.valueOf(msg.get("elasticsearch.slowlog.took"));
142+
long tookMillisExpected = took / 1_000_000L;
143+
long tookMillis = Long.valueOf(msg.get("elasticsearch.slowlog.took_millis"));
144+
assertThat(took, is(actualTook[i]));
145+
assertThat(tookMillis, is(tookMillisExpected));
146+
assertThat(msg.get("elasticsearch.slowlog.planning.took"), is(nullValue()));
147+
assertThat(msg.get("elasticsearch.slowlog.planning.took_millis"), is(nullValue()));
148+
assertThat(msg.get("elasticsearch.slowlog.query"), is(query));
149+
assertThat(appender.getLastEventAndReset().getLevel(), equalTo(expectedLevel[i]));
150+
} else {
151+
assertThat(appender.lastEvent(), is(nullValue()));
152+
}
153+
}
154+
}
155+
156+
private static EsqlExecutionInfo getEsqlExecutionInfo(long tookNanos, long planningTookNanos) {
157+
EsqlExecutionInfo info = new EsqlExecutionInfo(false) {
158+
@Override
159+
public TimeValue overallTook() {
160+
return new TimeValue(tookNanos, TimeUnit.NANOSECONDS);
161+
}
162+
163+
@Override
164+
public TimeValue planningTookTime() {
165+
return new TimeValue(planningTookNanos, TimeUnit.NANOSECONDS);
166+
}
167+
};
168+
return info;
169+
}
170+
}

‎x-pack/plugin/esql/src/test/java/org/elasticsearch/xpack/esql/slowlog/MockAppender.java‎

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,40 @@
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.slowlog;
9+
10+
import org.apache.logging.log4j.core.LogEvent;
11+
import org.apache.logging.log4j.core.appender.AbstractAppender;
12+
import org.apache.logging.log4j.core.filter.RegexFilter;
13+
import org.apache.logging.log4j.message.Message;
14+
15+
public class MockAppender extends AbstractAppender {
16+
public LogEvent lastEvent;
17+
18+
public MockAppender(final String name) throws IllegalAccessException {
19+
super(name, RegexFilter.createFilter(".*(\n.*)*", new String[0], false, null, null), null, false);
20+
}
21+
22+
@Override
23+
public void append(LogEvent event) {
24+
lastEvent = event.toImmutable();
25+
}
26+
27+
Message lastMessage() {
28+
return lastEvent.getMessage();
29+
}
30+
31+
LogEvent lastEvent() {
32+
return lastEvent;
33+
}
34+
35+
public LogEvent getLastEventAndReset() {
36+
LogEvent toReturn = lastEvent;
37+
lastEvent = null;
38+
return toReturn;
39+
}
40+
}

0 commit comments

Comments
 (0)