Skip to content

Commit ace1dcc

Browse files
authored
[7.17] Add trace.id to request trace logs (#91772) (#91860)
* Add trace.id to request trace logs (#91772) This adds trace.id, extracted from traceparent header, so its present in the request trace log. It is already included in response trace logs via the threadcontext, but that is not set at request log time.
1 parent 983999f commit ace1dcc

File tree

5 files changed

+119
-5
lines changed

5 files changed

+119
-5
lines changed

docs/changelog/91772.yaml

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
pr: 91772
2+
summary: Add `trace.id` to request trace logs
3+
area: Infra/Core
4+
type: bug
5+
issues: [88174]

server/src/main/java/org/elasticsearch/http/HttpTracer.java

Lines changed: 12 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
import org.elasticsearch.core.Nullable;
1818
import org.elasticsearch.rest.RestRequest;
1919
import org.elasticsearch.rest.RestResponse;
20+
import org.elasticsearch.rest.RestUtils;
2021
import org.elasticsearch.tasks.Task;
2122
import org.elasticsearch.transport.TransportService;
2223

@@ -32,6 +33,11 @@ class HttpTracer {
3233
private volatile String[] tracerLogInclude;
3334
private volatile String[] tracerLogExclude;
3435

36+
// for testing
37+
HttpTracer() {
38+
tracerLogInclude = tracerLogExclude = new String[0];
39+
}
40+
3541
HttpTracer(Settings settings, ClusterSettings clusterSettings) {
3642

3743
setTracerLogInclude(HttpTransportSettings.SETTING_HTTP_TRACE_LOG_INCLUDE.get(settings));
@@ -54,14 +60,17 @@ class HttpTracer {
5460
@Nullable
5561
HttpTracer maybeTraceRequest(RestRequest restRequest, @Nullable Exception e) {
5662
if (logger.isTraceEnabled() && TransportService.shouldTraceAction(restRequest.uri(), tracerLogInclude, tracerLogExclude)) {
63+
// trace.id in the response log is included from threadcontext, which isn't set at request log time
64+
// so include it here as part of the message
5765
logger.trace(
5866
new ParameterizedMessage(
59-
"[{}][{}][{}][{}] received request from [{}]",
67+
"[{}][{}][{}][{}] received request from [{}]{}",
6068
restRequest.getRequestId(),
6169
restRequest.header(Task.X_OPAQUE_ID_HTTP_HEADER),
6270
restRequest.method(),
6371
restRequest.uri(),
64-
restRequest.getHttpChannel()
72+
restRequest.getHttpChannel(),
73+
RestUtils.extractTraceId(restRequest.header(Task.TRACE_PARENT_HTTP_HEADER)).map(t -> " trace.id: " + t).orElse("")
6574
),
6675
e
6776
);
@@ -88,6 +97,7 @@ void traceResponse(
8897
long requestId,
8998
boolean success
9099
) {
100+
// trace id is included in the ThreadContext for the response
91101
logger.trace(
92102
new ParameterizedMessage(
93103
"[{}][{}][{}][{}][{}] sent response to [{}] success [{}]",

server/src/main/java/org/elasticsearch/rest/RestController.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,7 @@
4040
import java.util.Iterator;
4141
import java.util.List;
4242
import java.util.Map;
43+
import java.util.Optional;
4344
import java.util.Set;
4445
import java.util.concurrent.atomic.AtomicBoolean;
4546
import java.util.function.Supplier;
@@ -420,8 +421,9 @@ private void copyRestHeaders(RestRequest request, ThreadContext threadContext) t
420421
throw new IllegalArgumentException("multiple values for single-valued header [" + name + "].");
421422
} else if (name.equals(Task.TRACE_PARENT_HTTP_HEADER)) {
422423
String traceparent = distinctHeaderValues.get(0);
423-
if (traceparent.length() >= 55) {
424-
threadContext.putHeader(Task.TRACE_ID, traceparent.substring(3, 35));
424+
Optional<String> traceId = RestUtils.extractTraceId(traceparent);
425+
if (traceId.isPresent()) {
426+
threadContext.putHeader(Task.TRACE_ID, traceId.get());
425427
}
426428
} else {
427429
threadContext.putHeader(name, String.join(",", distinctHeaderValues));

server/src/main/java/org/elasticsearch/rest/RestUtils.java

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616
import java.nio.charset.StandardCharsets;
1717
import java.util.Arrays;
1818
import java.util.Map;
19+
import java.util.Optional;
1920
import java.util.regex.Pattern;
2021

2122
public class RestUtils {
@@ -241,6 +242,18 @@ public static String[] corsSettingAsArray(String corsSetting) {
241242
if (Strings.isNullOrEmpty(corsSetting)) {
242243
return new String[0];
243244
}
244-
return Arrays.asList(corsSetting.split(",")).stream().map(String::trim).toArray(size -> new String[size]);
245+
return Arrays.stream(corsSetting.split(",")).map(String::trim).toArray(String[]::new);
245246
}
247+
248+
/**
249+
* Extract the trace id from the specified traceparent string.
250+
* @see <a href="https://www.w3.org/TR/trace-context/#traceparent-header">W3 traceparent spec</a>
251+
*
252+
* @param traceparent The value from the {@code traceparent} HTTP header
253+
* @return The trace id from the traceparent string, or {@code Optional.empty()} if it is not present.
254+
*/
255+
public static Optional<String> extractTraceId(String traceparent) {
256+
return traceparent != null && traceparent.length() >= 55 ? Optional.of(traceparent.substring(3, 35)) : Optional.empty();
257+
}
258+
246259
}
Lines changed: 84 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,84 @@
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 and the Server Side Public License, v 1; you may not use this file except
5+
* in compliance with, at your election, the Elastic License 2.0 or the Server
6+
* Side Public License, v 1.
7+
*/
8+
9+
package org.elasticsearch.http;
10+
11+
import org.apache.logging.log4j.Level;
12+
import org.apache.logging.log4j.LogManager;
13+
import org.elasticsearch.common.logging.Loggers;
14+
import org.elasticsearch.rest.BytesRestResponse;
15+
import org.elasticsearch.rest.RestRequest;
16+
import org.elasticsearch.rest.RestStatus;
17+
import org.elasticsearch.tasks.Task;
18+
import org.elasticsearch.test.ESTestCase;
19+
import org.elasticsearch.test.MockLogAppender;
20+
import org.elasticsearch.test.junit.annotations.TestLogging;
21+
import org.elasticsearch.test.rest.FakeRestRequest;
22+
import org.elasticsearch.xcontent.NamedXContentRegistry;
23+
24+
import java.net.InetSocketAddress;
25+
import java.util.Collections;
26+
import java.util.HashMap;
27+
import java.util.List;
28+
import java.util.Map;
29+
30+
public class HttpTracerTests extends ESTestCase {
31+
32+
@TestLogging(reason = "Get HttpTracer to output trace logs", value = "org.elasticsearch.http.HttpTracer:TRACE")
33+
public void testLogging() throws IllegalAccessException {
34+
String httpTracerLog = HttpTracer.class.getName();
35+
36+
MockLogAppender appender = new MockLogAppender();
37+
try {
38+
appender.start();
39+
Loggers.addAppender(LogManager.getLogger(httpTracerLog), appender);
40+
41+
appender.addExpectation(
42+
new MockLogAppender.PatternSeenEventExpectation(
43+
"request log",
44+
httpTracerLog,
45+
Level.TRACE,
46+
"\\[\\d+]\\[idHeader]\\[GET]\\[uri] received request from \\[.*] trace.id: 4bf92f3577b34da6a3ce929d0e0e4736"
47+
)
48+
);
49+
appender.addExpectation(
50+
new MockLogAppender.PatternSeenEventExpectation(
51+
"response log",
52+
httpTracerLog,
53+
Level.TRACE,
54+
"\\[\\d+]\\[idHeader]\\[ACCEPTED]\\[text/plain; charset=UTF-8]\\[length] sent response to \\[.*] success \\[true]"
55+
)
56+
);
57+
58+
Map<String, List<String>> headers = new HashMap<>();
59+
headers.put(Task.X_OPAQUE_ID_HTTP_HEADER, Collections.singletonList("idHeader"));
60+
headers.put("traceparent", Collections.singletonList("00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"));
61+
62+
RestRequest request = new FakeRestRequest.Builder(new NamedXContentRegistry(Collections.emptyList())).withMethod(
63+
RestRequest.Method.GET
64+
).withPath("uri").withHeaders(headers).build();
65+
66+
HttpTracer tracer = new HttpTracer().maybeTraceRequest(request, null);
67+
assertNotNull(tracer);
68+
69+
tracer.traceResponse(
70+
new BytesRestResponse(RestStatus.ACCEPTED, ""),
71+
new FakeRestRequest.FakeHttpChannel(InetSocketAddress.createUnresolved("127.0.0.1", 9200)),
72+
"length",
73+
"idHeader",
74+
1L,
75+
true
76+
);
77+
78+
appender.assertAllExpectationsMatched();
79+
} finally {
80+
Loggers.removeAppender(LogManager.getLogger(httpTracerLog), appender);
81+
appender.stop();
82+
}
83+
}
84+
}

0 commit comments

Comments
 (0)