Skip to content

Commit 9ef7abb

Browse files
committed
Add task ID to log
1 parent 0a22ea9 commit 9ef7abb

File tree

3 files changed

+33
-12
lines changed

3 files changed

+33
-12
lines changed

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

+11-2
Original file line numberDiff line numberDiff line change
@@ -567,6 +567,7 @@ protected void doClose() {
567567
* @param version channel version of the request
568568
* @param nodeId id of the current node
569569
* @param shardId id of the shard being searched
570+
* @param taskId id of the task being executed
570571
* @param threadPool with context where to write the new header
571572
* @return the wrapped action listener
572573
*/
@@ -575,6 +576,7 @@ static <T> ActionListener<T> maybeWrapListenerForStackTrace(
575576
TransportVersion version,
576577
String nodeId,
577578
ShardId shardId,
579+
long taskId,
578580
ThreadPool threadPool
579581
) {
580582
boolean header = true;
@@ -584,10 +586,12 @@ static <T> ActionListener<T> maybeWrapListenerForStackTrace(
584586
if (header == false) {
585587
return listener.delegateResponse((l, e) -> {
586588
org.apache.logging.log4j.util.Supplier<String> messageSupplier = () -> format(
587-
"[%s]%s: failed to execute search request",
589+
"[%s]%s: failed to execute search request for task [%d]",
588590
nodeId,
589-
shardId
591+
shardId,
592+
taskId
590593
);
594+
// Keep this logic aligned with that of SUPPRESSED_ERROR_LOGGER in RestResponse
591595
if (ExceptionsHelper.status(e).getStatus() < 500 || ExceptionsHelper.isNodeOrShardUnavailableTypeException(e)) {
592596
logger.debug(messageSupplier, e);
593597
} else {
@@ -609,6 +613,7 @@ public void executeDfsPhase(ShardSearchRequest request, SearchShardTask task, Ac
609613
request.getChannelVersion(),
610614
clusterService.localNode().getId(),
611615
request.shardId(),
616+
task.getId(),
612617
threadPool
613618
);
614619
final IndexShard shard = getShard(request);
@@ -659,6 +664,7 @@ public void executeQueryPhase(ShardSearchRequest request, CancellableTask task,
659664
request.getChannelVersion(),
660665
clusterService.localNode().getId(),
661666
request.shardId(),
667+
task.getId(),
662668
threadPool
663669
).delegateFailure((l, orig) -> {
664670
// check if we can shortcut the query phase entirely.
@@ -865,6 +871,7 @@ public void executeRankFeaturePhase(RankFeatureShardRequest request, SearchShard
865871
shardSearchRequest.getChannelVersion(),
866872
clusterService.localNode().getId(),
867873
shardSearchRequest.shardId(),
874+
task.getId(),
868875
threadPool
869876
);
870877
final Releasable markAsUsed = readerContext.markAsUsed(getKeepAlive(shardSearchRequest));
@@ -921,6 +928,7 @@ public void executeQueryPhase(
921928
version,
922929
clusterService.localNode().getId(),
923930
readerContext.indexShard().shardId(),
931+
task.getId(),
924932
threadPool
925933
);
926934
final Releasable markAsUsed;
@@ -977,6 +985,7 @@ public void executeQueryPhase(
977985
version,
978986
clusterService.localNode().getId(),
979987
shardSearchRequest.shardId(),
988+
task.getId(),
980989
threadPool
981990
);
982991
final Releasable markAsUsed = readerContext.markAsUsed(getKeepAlive(shardSearchRequest));

server/src/test/java/org/elasticsearch/search/SearchServiceTests.java

+9-7
Original file line numberDiff line numberDiff line change
@@ -151,7 +151,7 @@ public void onFailure(Exception e) {
151151
e.fillInStackTrace();
152152
assertThat(e.getStackTrace().length, is(not(0)));
153153
listener.onFailure(e);
154-
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), "node", shardId, threadPool);
154+
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), "node", shardId, 123L, threadPool);
155155
isWrapped.set(true);
156156
listener.onFailure(e);
157157
}
@@ -160,16 +160,17 @@ public void testMaybeWrapListenerForStackTraceDebugLog() {
160160
final String nodeId = "node";
161161
final String index = "index";
162162
ShardId shardId = new ShardId(index, index, 0);
163+
final long taskId = 123L;
163164

164165
try (var mockLog = MockLog.capture(SearchService.class)) {
165166
Configurator.setLevel(SearchService.class, Level.DEBUG);
166167
final String exceptionMessage = "test exception message";
167168
mockLog.addExpectation(
168169
new MockLog.ExceptionSeenEventExpectation(
169-
format("\"[%s]%s: failed to execute search request\" and an exception logged", nodeId, shardId),
170+
format("\"[%s]%s: failed to execute search request for task [%d]\" and an exception logged", nodeId, shardId, taskId),
170171
SearchService.class.getCanonicalName(),
171172
Level.DEBUG, // We will throw a 400-level exception, so it should only be logged at the debug level
172-
format("[%s]%s: failed to execute search request", nodeId, shardId),
173+
format("[%s]%s: failed to execute search request for task [%d]", nodeId, shardId, taskId),
173174
IllegalArgumentException.class,
174175
exceptionMessage
175176
)
@@ -188,7 +189,7 @@ public void onFailure(Exception e) {
188189
}
189190
};
190191
IllegalArgumentException e = new IllegalArgumentException(exceptionMessage); // 400-level exception
191-
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), nodeId, shardId, threadPool);
192+
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), nodeId, shardId, taskId, threadPool);
192193
listener.onFailure(e);
193194
}
194195
}
@@ -197,15 +198,16 @@ public void testMaybeWrapListenerForStackTraceWarnLog() {
197198
final String nodeId = "node";
198199
final String index = "index";
199200
ShardId shardId = new ShardId(index, index, 0);
201+
final long taskId = 123L;
200202

201203
try (var mockLog = MockLog.capture(SearchService.class)) {
202204
final String exceptionMessage = "test exception message";
203205
mockLog.addExpectation(
204206
new MockLog.ExceptionSeenEventExpectation(
205-
format("\"[%s]%s: failed to execute search request\" and an exception logged", nodeId, shardId),
207+
format("\"[%s]%s: failed to execute search request for task [%d]\" and an exception logged", nodeId, shardId, taskId),
206208
SearchService.class.getCanonicalName(),
207209
Level.WARN, // We will throw a 500-level exception, so it should be logged at the warn level
208-
format("[%s]%s: failed to execute search request", nodeId, shardId),
210+
format("[%s]%s: failed to execute search request for task [%d]", nodeId, shardId, taskId),
209211
IllegalStateException.class,
210212
exceptionMessage
211213
)
@@ -224,7 +226,7 @@ public void onFailure(Exception e) {
224226
}
225227
};
226228
IllegalStateException e = new IllegalStateException(exceptionMessage); // 500-level exception
227-
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), nodeId, shardId, threadPool);
229+
listener = maybeWrapListenerForStackTrace(listener, TransportVersion.current(), nodeId, shardId, taskId, threadPool);
228230
listener.onFailure(e);
229231
}
230232
}

test/framework/src/main/java/org/elasticsearch/search/ErrorTraceHelper.java

+13-3
Original file line numberDiff line numberDiff line change
@@ -71,14 +71,19 @@ public static void addSeenLoggingExpectations(int numShards, MockLog mockLog, St
7171
mockLog.addExpectation(
7272
new MockLog.PatternAndExceptionSeenEventExpectation(
7373
format(
74-
"\"[%s][%s][%d]: failed to execute search request\" and an exception logged",
74+
"\"[%s][%s][%d]: failed to execute search request for task [\\d+]\" and an exception logged",
7575
nodesDisjunction,
7676
errorTriggeringIndex,
7777
shard
7878
),
7979
SearchService.class.getCanonicalName(),
8080
Level.DEBUG,
81-
format("\\[%s\\]\\[%s\\]\\[%d\\]: failed to execute search request", nodesDisjunction, errorTriggeringIndex, shard),
81+
format(
82+
"\\[%s\\]\\[%s\\]\\[%d\\]: failed to execute search request for task \\[\\d+\\]",
83+
nodesDisjunction,
84+
errorTriggeringIndex,
85+
shard
86+
),
8287
QueryShardException.class,
8388
"failed to create query: For input string: \"foo\""
8489
)
@@ -99,7 +104,12 @@ public static void addUnseenLoggingExpectations(int numShards, MockLog mockLog,
99104
for (int shard = 0; shard < numShards; shard++) {
100105
mockLog.addExpectation(
101106
new MockLog.UnseenEventExpectation(
102-
"\"[%s][%s][%d]: failed to execute search request\" and an exception logged",
107+
format(
108+
"\"[%s][%s][%d]: failed to execute search request\" and an exception logged",
109+
getNodeId(nodeName),
110+
errorTriggeringIndex,
111+
shard
112+
),
103113
SearchService.class.getCanonicalName(),
104114
Level.DEBUG,
105115
format("[%s][%s][%d]: failed to execute search request", getNodeId(nodeName), errorTriggeringIndex, shard)

0 commit comments

Comments
 (0)