Skip to content

Commit 519086a

Browse files
authored
Move SlowLogFieldProvider instantiation to node construction (elastic#117949) (elastic#119602)
SPI from plugins should be created at node startup. This commit moves creation of SlowLogFieldProvider into node construction and passes it in to IndicesService so that it is not recreated on each index creation. relates elastic#102103
1 parent 8daac20 commit 519086a

File tree

13 files changed

+200
-164
lines changed

13 files changed

+200
-164
lines changed

docs/changelog/117949.yaml

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
pr: 117949
2+
summary: Move `SlowLogFieldProvider` instantiation to node construction
3+
area: Infra/Logging
4+
type: bug
5+
issues: []

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

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -208,8 +208,9 @@ public IndexModule(
208208
this.engineFactory = Objects.requireNonNull(engineFactory);
209209
// Need to have a mutable arraylist for plugins to add listeners to it
210210
this.searchOperationListeners = new ArrayList<>(searchOperationListeners);
211-
this.searchOperationListeners.add(new SearchSlowLog(indexSettings, slowLogFieldProvider));
212-
this.indexOperationListeners.add(new IndexingSlowLog(indexSettings, slowLogFieldProvider));
211+
SlowLogFields slowLogFields = slowLogFieldProvider.create(indexSettings);
212+
this.searchOperationListeners.add(new SearchSlowLog(indexSettings, slowLogFields));
213+
this.indexOperationListeners.add(new IndexingSlowLog(indexSettings, slowLogFields));
213214
this.directoryFactories = Collections.unmodifiableMap(directoryFactories);
214215
this.allowExpensiveQueries = allowExpensiveQueries;
215216
this.expressionResolver = expressionResolver;

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

Lines changed: 7 additions & 35 deletions
Original file line numberDiff line numberDiff line change
@@ -103,7 +103,7 @@ public final class IndexingSlowLog implements IndexingOperationListener {
103103
* <em>characters</em> of the source.
104104
*/
105105
private int maxSourceCharsToLog;
106-
private final SlowLogFieldProvider slowLogFieldProvider;
106+
private final SlowLogFields slowLogFields;
107107

108108
/**
109109
* Reads how much of the source to log. The user can specify any value they
@@ -125,8 +125,8 @@ public final class IndexingSlowLog implements IndexingOperationListener {
125125
Property.IndexScope
126126
);
127127

128-
IndexingSlowLog(IndexSettings indexSettings, SlowLogFieldProvider slowLogFieldProvider) {
129-
this.slowLogFieldProvider = slowLogFieldProvider;
128+
IndexingSlowLog(IndexSettings indexSettings, SlowLogFields slowLogFields) {
129+
this.slowLogFields = slowLogFields;
130130
this.index = indexSettings.getIndex();
131131

132132
indexSettings.getScopedSettings().addSettingsUpdateConsumer(INDEX_INDEXING_SLOWLOG_REFORMAT_SETTING, this::setReformat);
@@ -179,47 +179,19 @@ public void postIndex(ShardId shardId, Engine.Index indexOperation, Engine.Index
179179
final long tookInNanos = result.getTook();
180180
if (indexWarnThreshold >= 0 && tookInNanos > indexWarnThreshold) {
181181
indexLogger.warn(
182-
IndexingSlowLogMessage.of(
183-
this.slowLogFieldProvider.indexSlowLogFields(),
184-
index,
185-
doc,
186-
tookInNanos,
187-
reformat,
188-
maxSourceCharsToLog
189-
)
182+
IndexingSlowLogMessage.of(this.slowLogFields.indexFields(), index, doc, tookInNanos, reformat, maxSourceCharsToLog)
190183
);
191184
} else if (indexInfoThreshold >= 0 && tookInNanos > indexInfoThreshold) {
192185
indexLogger.info(
193-
IndexingSlowLogMessage.of(
194-
this.slowLogFieldProvider.indexSlowLogFields(),
195-
index,
196-
doc,
197-
tookInNanos,
198-
reformat,
199-
maxSourceCharsToLog
200-
)
186+
IndexingSlowLogMessage.of(this.slowLogFields.indexFields(), index, doc, tookInNanos, reformat, maxSourceCharsToLog)
201187
);
202188
} else if (indexDebugThreshold >= 0 && tookInNanos > indexDebugThreshold) {
203189
indexLogger.debug(
204-
IndexingSlowLogMessage.of(
205-
this.slowLogFieldProvider.indexSlowLogFields(),
206-
index,
207-
doc,
208-
tookInNanos,
209-
reformat,
210-
maxSourceCharsToLog
211-
)
190+
IndexingSlowLogMessage.of(this.slowLogFields.indexFields(), index, doc, tookInNanos, reformat, maxSourceCharsToLog)
212191
);
213192
} else if (indexTraceThreshold >= 0 && tookInNanos > indexTraceThreshold) {
214193
indexLogger.trace(
215-
IndexingSlowLogMessage.of(
216-
this.slowLogFieldProvider.indexSlowLogFields(),
217-
index,
218-
doc,
219-
tookInNanos,
220-
reformat,
221-
maxSourceCharsToLog
222-
)
194+
IndexingSlowLogMessage.of(this.slowLogFields.indexFields(), index, doc, tookInNanos, reformat, maxSourceCharsToLog)
223195
);
224196
}
225197
}

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

Lines changed: 11 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,7 @@ public final class SearchSlowLog implements SearchOperationListener {
4545
private static final Logger queryLogger = LogManager.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".query");
4646
private static final Logger fetchLogger = LogManager.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".fetch");
4747

48-
private final SlowLogFieldProvider slowLogFieldProvider;
48+
private final SlowLogFields slowLogFields;
4949

5050
public static final Setting<Boolean> INDEX_SEARCH_SLOWLOG_INCLUDE_USER_SETTING = Setting.boolSetting(
5151
INDEX_SEARCH_SLOWLOG_PREFIX + ".include.user",
@@ -126,9 +126,8 @@ public final class SearchSlowLog implements SearchOperationListener {
126126

127127
private static final ToXContent.Params FORMAT_PARAMS = new ToXContent.MapParams(Collections.singletonMap("pretty", "false"));
128128

129-
public SearchSlowLog(IndexSettings indexSettings, SlowLogFieldProvider slowLogFieldProvider) {
130-
slowLogFieldProvider.init(indexSettings);
131-
this.slowLogFieldProvider = slowLogFieldProvider;
129+
public SearchSlowLog(IndexSettings indexSettings, SlowLogFields slowLogFields) {
130+
this.slowLogFields = slowLogFields;
132131
indexSettings.getScopedSettings()
133132
.addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_WARN_SETTING, this::setQueryWarnThreshold);
134133
this.queryWarnThreshold = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_THRESHOLD_QUERY_WARN_SETTING).nanos();
@@ -159,26 +158,26 @@ public SearchSlowLog(IndexSettings indexSettings, SlowLogFieldProvider slowLogFi
159158
@Override
160159
public void onQueryPhase(SearchContext context, long tookInNanos) {
161160
if (queryWarnThreshold >= 0 && tookInNanos > queryWarnThreshold) {
162-
queryLogger.warn(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
161+
queryLogger.warn(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
163162
} else if (queryInfoThreshold >= 0 && tookInNanos > queryInfoThreshold) {
164-
queryLogger.info(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
163+
queryLogger.info(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
165164
} else if (queryDebugThreshold >= 0 && tookInNanos > queryDebugThreshold) {
166-
queryLogger.debug(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
165+
queryLogger.debug(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
167166
} else if (queryTraceThreshold >= 0 && tookInNanos > queryTraceThreshold) {
168-
queryLogger.trace(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
167+
queryLogger.trace(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
169168
}
170169
}
171170

172171
@Override
173172
public void onFetchPhase(SearchContext context, long tookInNanos) {
174173
if (fetchWarnThreshold >= 0 && tookInNanos > fetchWarnThreshold) {
175-
fetchLogger.warn(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
174+
fetchLogger.warn(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
176175
} else if (fetchInfoThreshold >= 0 && tookInNanos > fetchInfoThreshold) {
177-
fetchLogger.info(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
176+
fetchLogger.info(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
178177
} else if (fetchDebugThreshold >= 0 && tookInNanos > fetchDebugThreshold) {
179-
fetchLogger.debug(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
178+
fetchLogger.debug(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
180179
} else if (fetchTraceThreshold >= 0 && tookInNanos > fetchTraceThreshold) {
181-
fetchLogger.trace(SearchSlowLogMessage.of(this.slowLogFieldProvider.searchSlowLogFields(), context, tookInNanos));
180+
fetchLogger.trace(SearchSlowLogMessage.of(this.slowLogFields.searchFields(), context, tookInNanos));
182181
}
183182
}
184183

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

Lines changed: 2 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -9,28 +9,14 @@
99

1010
package org.elasticsearch.index;
1111

12-
import java.util.Map;
13-
1412
/**
1513
* Interface for providing additional fields to the slow log from a plugin.
1614
* Intended to be loaded through SPI.
1715
*/
1816
public interface SlowLogFieldProvider {
1917
/**
20-
* Initialize field provider with index level settings to be able to listen for updates and set initial values
18+
* Create a field provider with index level settings to be able to listen for updates and set initial values
2119
* @param indexSettings settings for the index
2220
*/
23-
void init(IndexSettings indexSettings);
24-
25-
/**
26-
* Slow log fields for indexing events
27-
* @return map of field name to value
28-
*/
29-
Map<String, String> indexSlowLogFields();
30-
31-
/**
32-
* Slow log fields for search events
33-
* @return map of field name to value
34-
*/
35-
Map<String, String> searchSlowLogFields();
21+
SlowLogFields create(IndexSettings indexSettings);
3622
}
Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,30 @@
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", the "GNU Affero General Public License v3.0 only", and the "Server Side
5+
* Public License v 1"; you may not use this file except in compliance with, at
6+
* your election, the "Elastic License 2.0", the "GNU Affero General Public
7+
* License v3.0 only", or the "Server Side Public License, v 1".
8+
*/
9+
10+
package org.elasticsearch.index;
11+
12+
import java.util.Map;
13+
14+
/**
15+
* Fields for the slow log. These may be different each call depending on the state of the system.
16+
*/
17+
public interface SlowLogFields {
18+
19+
/**
20+
* Slow log fields for indexing events
21+
* @return map of field name to value
22+
*/
23+
Map<String, String> indexFields();
24+
25+
/**
26+
* Slow log fields for search events
27+
* @return map of field name to value
28+
*/
29+
Map<String, String> searchFields();
30+
}

server/src/main/java/org/elasticsearch/indices/IndicesService.java

Lines changed: 4 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -267,6 +267,7 @@ public class IndicesService extends AbstractLifecycleComponent
267267
private final MapperMetrics mapperMetrics;
268268
private final List<SearchOperationListener> searchOperationListeners;
269269
private final QueryRewriteInterceptor queryRewriteInterceptor;
270+
final SlowLogFieldProvider slowLogFieldProvider; // pkg-private for testingå
270271

271272
@Override
272273
protected void doStart() {
@@ -385,6 +386,7 @@ public void onRemoval(ShardId shardId, String fieldName, boolean wasEvicted, lon
385386

386387
this.timestampFieldMapperService = new TimestampFieldMapperService(settings, threadPool, this);
387388
this.searchOperationListeners = builder.searchOperationListener;
389+
this.slowLogFieldProvider = builder.slowLogFieldProvider;
388390
}
389391

390392
private static final String DANGLING_INDICES_UPDATE_THREAD_NAME = "DanglingIndices#updateTask";
@@ -755,7 +757,7 @@ private synchronized IndexService createIndexService(
755757
() -> allowExpensiveQueries,
756758
indexNameExpressionResolver,
757759
recoveryStateFactories,
758-
loadSlowLogFieldProvider(),
760+
slowLogFieldProvider,
759761
mapperMetrics,
760762
searchOperationListeners
761763
);
@@ -835,7 +837,7 @@ public synchronized MapperService createIndexMapperServiceForValidation(IndexMet
835837
() -> allowExpensiveQueries,
836838
indexNameExpressionResolver,
837839
recoveryStateFactories,
838-
loadSlowLogFieldProvider(),
840+
slowLogFieldProvider,
839841
mapperMetrics,
840842
searchOperationListeners
841843
);
@@ -1437,31 +1439,6 @@ int numPendingDeletes(Index index) {
14371439
}
14381440
}
14391441

1440-
// pkg-private for testing
1441-
SlowLogFieldProvider loadSlowLogFieldProvider() {
1442-
List<? extends SlowLogFieldProvider> slowLogFieldProviders = pluginsService.loadServiceProviders(SlowLogFieldProvider.class);
1443-
return new SlowLogFieldProvider() {
1444-
@Override
1445-
public void init(IndexSettings indexSettings) {
1446-
slowLogFieldProviders.forEach(provider -> provider.init(indexSettings));
1447-
}
1448-
1449-
@Override
1450-
public Map<String, String> indexSlowLogFields() {
1451-
return slowLogFieldProviders.stream()
1452-
.flatMap(provider -> provider.indexSlowLogFields().entrySet().stream())
1453-
.collect(Collectors.toMap(Map.Entry::getKey, Map.Entry::getValue));
1454-
}
1455-
1456-
@Override
1457-
public Map<String, String> searchSlowLogFields() {
1458-
return slowLogFieldProviders.stream()
1459-
.flatMap(provider -> provider.searchSlowLogFields().entrySet().stream())
1460-
.collect(Collectors.toMap(Map.Entry::getKey, Map.Entry::getValue));
1461-
}
1462-
};
1463-
}
1464-
14651442
/**
14661443
* Checks if all pending deletes have completed. Used by tests to ensure we don't check directory contents
14671444
* while deletion still ongoing. * The reason is that, on Windows, browsing the directory contents can interfere

server/src/main/java/org/elasticsearch/indices/IndicesServiceBuilder.java

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,8 @@
2323
import org.elasticsearch.features.FeatureService;
2424
import org.elasticsearch.gateway.MetaStateService;
2525
import org.elasticsearch.index.IndexSettings;
26+
import org.elasticsearch.index.SlowLogFieldProvider;
27+
import org.elasticsearch.index.SlowLogFields;
2628
import org.elasticsearch.index.analysis.AnalysisRegistry;
2729
import org.elasticsearch.index.engine.EngineFactory;
2830
import org.elasticsearch.index.mapper.MapperMetrics;
@@ -79,6 +81,22 @@ public class IndicesServiceBuilder {
7981
MapperMetrics mapperMetrics;
8082
List<SearchOperationListener> searchOperationListener = List.of();
8183
QueryRewriteInterceptor queryRewriteInterceptor = null;
84+
SlowLogFieldProvider slowLogFieldProvider = new SlowLogFieldProvider() {
85+
@Override
86+
public SlowLogFields create(IndexSettings indexSettings) {
87+
return new SlowLogFields() {
88+
@Override
89+
public Map<String, String> indexFields() {
90+
return Map.of();
91+
}
92+
93+
@Override
94+
public Map<String, String> searchFields() {
95+
return Map.of();
96+
}
97+
};
98+
}
99+
};
82100

83101
public IndicesServiceBuilder settings(Settings settings) {
84102
this.settings = settings;
@@ -191,6 +209,11 @@ public IndicesServiceBuilder searchOperationListeners(List<SearchOperationListen
191209
return this;
192210
}
193211

212+
public IndicesServiceBuilder slowLogFieldProvider(SlowLogFieldProvider slowLogFieldProvider) {
213+
this.slowLogFieldProvider = slowLogFieldProvider;
214+
return this;
215+
}
216+
194217
public IndicesService build() {
195218
Objects.requireNonNull(settings);
196219
Objects.requireNonNull(pluginsService);
@@ -216,6 +239,7 @@ public IndicesService build() {
216239
Objects.requireNonNull(snapshotCommitSuppliers);
217240
Objects.requireNonNull(mapperMetrics);
218241
Objects.requireNonNull(searchOperationListener);
242+
Objects.requireNonNull(slowLogFieldProvider);
219243

220244
// collect engine factory providers from plugins
221245
engineFactoryProviders = pluginsService.filterPlugins(EnginePlugin.class)

server/src/main/java/org/elasticsearch/node/NodeConstruction.java

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -113,6 +113,8 @@
113113
import org.elasticsearch.index.IndexSettingProvider;
114114
import org.elasticsearch.index.IndexSettingProviders;
115115
import org.elasticsearch.index.IndexingPressure;
116+
import org.elasticsearch.index.SlowLogFieldProvider;
117+
import org.elasticsearch.index.SlowLogFields;
116118
import org.elasticsearch.index.analysis.AnalysisRegistry;
117119
import org.elasticsearch.index.mapper.MapperMetrics;
118120
import org.elasticsearch.index.mapper.SourceFieldMetrics;
@@ -808,6 +810,31 @@ private void construct(
808810
new ShardSearchPhaseAPMMetrics(telemetryProvider.getMeterRegistry())
809811
);
810812

813+
List<? extends SlowLogFieldProvider> slowLogFieldProviders = pluginsService.loadServiceProviders(SlowLogFieldProvider.class);
814+
// NOTE: the response of index/search slow log fields below must be calculated dynamically on every call
815+
// because the responses may change dynamically at runtime
816+
SlowLogFieldProvider slowLogFieldProvider = indexSettings -> {
817+
final List<SlowLogFields> fields = new ArrayList<>();
818+
for (var provider : slowLogFieldProviders) {
819+
fields.add(provider.create(indexSettings));
820+
}
821+
return new SlowLogFields() {
822+
@Override
823+
public Map<String, String> indexFields() {
824+
return fields.stream()
825+
.flatMap(f -> f.indexFields().entrySet().stream())
826+
.collect(Collectors.toMap(Map.Entry::getKey, Map.Entry::getValue));
827+
}
828+
829+
@Override
830+
public Map<String, String> searchFields() {
831+
return fields.stream()
832+
.flatMap(f -> f.searchFields().entrySet().stream())
833+
.collect(Collectors.toMap(Map.Entry::getKey, Map.Entry::getValue));
834+
}
835+
};
836+
};
837+
811838
IndicesService indicesService = new IndicesServiceBuilder().settings(settings)
812839
.pluginsService(pluginsService)
813840
.nodeEnvironment(nodeEnvironment)
@@ -829,6 +856,7 @@ private void construct(
829856
.requestCacheKeyDifferentiator(searchModule.getRequestCacheKeyDifferentiator())
830857
.mapperMetrics(mapperMetrics)
831858
.searchOperationListeners(searchOperationListeners)
859+
.slowLogFieldProvider(slowLogFieldProvider)
832860
.build();
833861

834862
final var parameters = new IndexSettingProvider.Parameters(clusterService, indicesService::createIndexMapperServiceForValidation);

0 commit comments

Comments
 (0)