Skip to content

Commit b2c71a5

Browse files
committed
dfs support slowlog
1 parent e602d56 commit b2c71a5

File tree

5 files changed

+116
-1
lines changed

5 files changed

+116
-1
lines changed

server/src/main/java/org/elasticsearch/common/settings/IndexScopedSettings.java

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,10 @@ public final class IndexScopedSettings extends AbstractScopedSettings {
9696
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_DEBUG_SETTING,
9797
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_INFO_SETTING,
9898
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_TRACE_SETTING,
99+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_TRACE_SETTING,
100+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_DEBUG_SETTING,
101+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_INFO_SETTING,
102+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_WARN_SETTING,
99103
SearchSlowLog.INDEX_SEARCH_SLOWLOG_INCLUDE_USER_SETTING,
100104
IndexingSlowLog.INDEX_INDEXING_SLOWLOG_THRESHOLD_INDEX_WARN_SETTING,
101105
IndexingSlowLog.INDEX_INDEXING_SLOWLOG_THRESHOLD_INDEX_DEBUG_SETTING,

server/src/main/java/org/elasticsearch/index/SearchSlowLog.java

Lines changed: 95 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,10 +40,16 @@ public final class SearchSlowLog implements SearchOperationListener {
4040
private long fetchDebugThreshold;
4141
private long fetchTraceThreshold;
4242

43+
private long dfsWarnThreshold;
44+
private long dfsInfoThreshold;
45+
private long dfsDebugThreshold;
46+
private long dfsTraceThreshold;
47+
4348
static final String INDEX_SEARCH_SLOWLOG_PREFIX = "index.search.slowlog";
4449

4550
private static final Logger queryLogger = LogManager.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".query");
4651
private static final Logger fetchLogger = LogManager.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".fetch");
52+
private static final Logger dfsLogger = LogManager.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".dfs");
4753

4854
private final SlowLogFields slowLogFields;
4955

@@ -109,6 +115,34 @@ public final class SearchSlowLog implements SearchOperationListener {
109115
Property.Dynamic,
110116
Property.IndexScope
111117
);
118+
public static final Setting<TimeValue> INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_WARN_SETTING = Setting.timeSetting(
119+
INDEX_SEARCH_SLOWLOG_PREFIX + ".threshold.dfs.warn",
120+
TimeValue.timeValueNanos(-1),
121+
TimeValue.timeValueMillis(-1),
122+
Property.Dynamic,
123+
Property.IndexScope
124+
);
125+
public static final Setting<TimeValue> INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_INFO_SETTING = Setting.timeSetting(
126+
INDEX_SEARCH_SLOWLOG_PREFIX + ".threshold.dfs.info",
127+
TimeValue.timeValueNanos(-1),
128+
TimeValue.timeValueMillis(-1),
129+
Property.Dynamic,
130+
Property.IndexScope
131+
);
132+
public static final Setting<TimeValue> INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_DEBUG_SETTING = Setting.timeSetting(
133+
INDEX_SEARCH_SLOWLOG_PREFIX + ".threshold.dfs.debug",
134+
TimeValue.timeValueNanos(-1),
135+
TimeValue.timeValueMillis(-1),
136+
Property.Dynamic,
137+
Property.IndexScope
138+
);
139+
public static final Setting<TimeValue> INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_TRACE_SETTING = Setting.timeSetting(
140+
INDEX_SEARCH_SLOWLOG_PREFIX + ".threshold.dfs.trace",
141+
TimeValue.timeValueNanos(-1),
142+
TimeValue.timeValueMillis(-1),
143+
Property.Dynamic,
144+
Property.IndexScope
145+
);
112146

113147
/**
114148
* Legacy index setting, kept for 7.x BWC compatibility. This setting has no effect in 8.x. Do not use.
@@ -153,6 +187,19 @@ public SearchSlowLog(IndexSettings indexSettings, SlowLogFields slowLogFields) {
153187
indexSettings.getScopedSettings()
154188
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_TRACE_SETTING, this::setFetchTraceThreshold);
155189
this.fetchTraceThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_TRACE_SETTING).nanos();
190+
191+
indexSettings.getScopedSettings()
192+
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_WARN_SETTING, this::setDfsWarnThreshold);
193+
this.fetchWarnThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_WARN_SETTING).nanos();
194+
indexSettings.getScopedSettings()
195+
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_INFO_SETTING, this::setDfsInfoThreshold);
196+
this.fetchInfoThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_INFO_SETTING).nanos();
197+
indexSettings.getScopedSettings()
198+
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_DEBUG_SETTING, this::setDfsDebugThreshold);
199+
this.fetchDebugThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_DEBUG_SETTING).nanos();
200+
indexSettings.getScopedSettings()
201+
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_TRACE_SETTING, this::setDfsTraceThreshold);
202+
this.fetchTraceThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_FETCH_TRACE_SETTING).nanos();
156203
}
157204

158205
@Override
@@ -181,6 +228,22 @@ public void onFetchPhase(SearchContext context, long tookInNanos) {
181228
}
182229
}
183230

231+
@Override
232+
public void onDfsPhase(SearchContext context, long tookInNanos) {
233+
if (dfsWarnThreshold >= 0 && tookInNanos > dfsWarnThreshold) {
234+
dfsLogger.warn(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
235+
}
236+
if (dfsInfoThreshold >= 0 && tookInNanos > dfsInfoThreshold) {
237+
dfsLogger.info(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
238+
}
239+
if (dfsDebugThreshold >= 0 && tookInNanos > dfsDebugThreshold) {
240+
dfsLogger.debug(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
241+
}
242+
if (dfsTraceThreshold >= 0 && tookInNanos > dfsTraceThreshold) {
243+
dfsLogger.trace(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
244+
}
245+
}
246+
184247
static final class SearchSlowLogMessage {
185248

186249
public static ESLogMessage of(Map<String, String> additionalFields, SearchContext context, long tookInNanos) {
@@ -256,6 +319,22 @@ private void setFetchTraceThreshold(TimeValue traceThreshold) {
256319
this.fetchTraceThreshold = traceThreshold.nanos();
257320
}
258321

322+
private void setDfsWarnThreshold(TimeValue warnThreshold) {
323+
this.dfsWarnThreshold = warnThreshold.nanos();
324+
}
325+
326+
private void setDfsInfoThreshold(TimeValue infoThreshold) {
327+
this.dfsInfoThreshold = infoThreshold.nanos();
328+
}
329+
330+
private void setDfsDebugThreshold(TimeValue debugThreshold) {
331+
this.dfsDebugThreshold = debugThreshold.nanos();
332+
}
333+
334+
private void setDfsTraceThreshold(TimeValue traceThreshold) {
335+
this.dfsTraceThreshold = traceThreshold.nanos();
336+
}
337+
259338
long getQueryWarnThreshold() {
260339
return queryWarnThreshold;
261340
}
@@ -288,4 +367,20 @@ long getFetchTraceThreshold() {
288367
return fetchTraceThreshold;
289368
}
290369

370+
long getDfsWarnThreshold() {
371+
return dfsWarnThreshold;
372+
}
373+
374+
long getDfsInfoThreshold() {
375+
return dfsInfoThreshold;
376+
}
377+
378+
long getDfsDebugThreshold() {
379+
return dfsDebugThreshold;
380+
}
381+
382+
long getDfsTraceThreshold() {
383+
return dfsTraceThreshold;
384+
}
385+
291386
}

server/src/main/java/org/elasticsearch/index/shard/SearchOperationListener.java

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,8 @@ default void onFailedFetchPhase(SearchContext searchContext) {}
6565
*/
6666
default void onFetchPhase(SearchContext searchContext, long tookInNanos) {}
6767

68+
default void onDfsPhase(SearchContext context, long tookInNanos) {}
69+
6870
/**
6971
* Executed when a new reader context was created
7072
* @param readerContext the created context

server/src/main/java/org/elasticsearch/search/SearchService.java

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -576,9 +576,11 @@ private DfsSearchResult executeDfsPhase(ShardSearchRequest request, SearchShardT
576576
try (@SuppressWarnings("unused") // withScope call is necessary to instrument search execution
577577
Releasable scope = tracer.withScope(task);
578578
Releasable ignored = readerContext.markAsUsed(getKeepAlive(request));
579-
SearchContext context = createContext(readerContext, request, task, ResultsType.DFS, false)
579+
SearchContext context = createContext(readerContext, request, task, ResultsType.DFS, false);
580+
SearchOperationListenerExecutor executor = new SearchOperationListenerExecutor(context)
580581
) {
581582
DfsPhase.execute(context);
583+
executor.success();
582584
return context.dfsResult();
583585
} catch (Exception e) {
584586
logger.trace("Dfs phase failed", e);
@@ -1982,6 +1984,7 @@ private static final class SearchOperationListenerExecutor implements AutoClosea
19821984
private final SearchContext context;
19831985
private final long time;
19841986
private final boolean fetch;
1987+
private final boolean dfs;
19851988
private long afterQueryTime = -1;
19861989
private boolean closed = false;
19871990

@@ -1990,10 +1993,15 @@ private static final class SearchOperationListenerExecutor implements AutoClosea
19901993
}
19911994

19921995
SearchOperationListenerExecutor(SearchContext context, boolean fetch, long startTime) {
1996+
this(context, fetch, false, startTime);
1997+
}
1998+
1999+
SearchOperationListenerExecutor(SearchContext context, boolean fetch, boolean dfs, long startTime) {
19932000
this.listener = context.indexShard().getSearchOperationListener();
19942001
this.context = context;
19952002
time = startTime;
19962003
this.fetch = fetch;
2004+
this.dfs = dfs;
19972005
if (fetch) {
19982006
listener.onPreFetchPhase(context);
19992007
} else {
@@ -2013,6 +2021,8 @@ public void close() {
20132021
if (afterQueryTime != -1) {
20142022
if (fetch) {
20152023
listener.onFetchPhase(context, afterQueryTime - time);
2024+
} else if (dfs) {
2025+
listener.onDfsPhase(context, afterQueryTime - time);
20162026
} else {
20172027
listener.onQueryPhase(context, afterQueryTime - time);
20182028
}

x-pack/plugin/ccr/src/main/java/org/elasticsearch/xpack/ccr/action/TransportResumeFollowAction.java

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -506,6 +506,10 @@ static String[] extractLeaderShardHistoryUUIDs(Map<String, String> ccrIndexMetad
506506
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_DEBUG_SETTING,
507507
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_INFO_SETTING,
508508
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_TRACE_SETTING,
509+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_WARN_SETTING,
510+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_INFO_SETTING,
511+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_DEBUG_SETTING,
512+
SearchSlowLog.INDEX_SEARCH_SLOWLOG_THRESHOLD_DFS_TRACE_SETTING,
509513
SearchSlowLog.INDEX_SEARCH_SLOWLOG_INCLUDE_USER_SETTING,
510514
IndexingSlowLog.INDEX_INDEXING_SLOWLOG_THRESHOLD_INDEX_WARN_SETTING,
511515
IndexingSlowLog.INDEX_INDEXING_SLOWLOG_THRESHOLD_INDEX_DEBUG_SETTING,

0 commit comments

Comments
 (0)