Adds minimal traceparent header support to Elasticsearch #74210

Mpdreamz · 2021-06-16T19:24:44Z

This adds just enough support for the traceparent header to be useful in master.

Since Elasticsearch already logs in ECS format extending it with support for transaction.id and trace.id is a quick win.

This allows us to surface server/deprecation slow logs from an instrumented application using the Trace Logs feature.

This forwards to Logs UI with a filter on trace.id

The parsing of the header itself is naive. I am hoping Elasticsearch in the future can take a dependency on the Java Agent OOTB (https://github.com/elastic/apm-agent-java) which ships with high performance parsing and validation routines. Which could then act as a jumping off point to manually instrument Elasticsearch.

We can work on incrementally adding value 🥳

NOTE: this needs #74211 to prevent clashes with Filebeat/ECS defaults

felixbarny · 2021-06-17T06:57:46Z

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

+                    String[] tokens  = traceparent.split("-");
+                    if (tokens.length == 4) {


Just as a suggestion: you could validate the length of the header. If it has the expected minimum length, use java.lang.String#substring(int, int) with the known offsets for the trace id and parent id.

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

felixbarny · 2021-06-17T06:59:33Z

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

@@ -570,7 +570,7 @@ protected Node(final Environment initialEnvironment,
            final Transport transport = networkModule.getTransportSupplier().get();
            Set<String> taskHeaders = Stream.concat(
                pluginsService.filterPlugins(ActionPlugin.class).stream().flatMap(p -> p.getTaskHeaders().stream()),
-                Stream.of(Task.X_OPAQUE_ID)
+                Stream.of(Task.X_OPAQUE_ID, Task.TRACE_PARENT)


Does this make sure the header gets propagated to other downstream ES nodes?

Afaik this makes sure the headers go over the transport wire to other nodes.

Even though it would technically render the traceparent header invalid, we may want to zero out the parent-id part of the header when sending to downstream nodes.

Kibana | traceparent: 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01 | v ES Node1 | traceparent: 00-0af7651916cd43dd8448eb211c80319c-0000000000000000-01 | v ES Node 2

That is because ES is not creating spans currently and thus there's no parent.
Based on the outcome of this discussion (#74210 (comment)), we don't need that part of the traceparent header anyway.

Removed transaction.id.

I personally prefer not zeroing out and treat ES as pass-through for now given this piece of information is no longer used.

This makes Elasticsearch accept `traceparent` header and makes sure its available as variable in log4j. By default ECS logger includes it.

elasticmachine · 2021-06-18T07:46:28Z

Pinging @elastic/es-core-infra (Team:Core/Infra)

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

…ThreadContext.java Co-authored-by: Rory Hunter <pugnascotia@users.noreply.github.com>

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

pgomulka

looks good!
can we also add testing in JsonLoggerTests ?
I am not sure what is the difference for trace_parent and trace_id ?

pgomulka · 2021-06-18T09:36:26Z

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

@@ -344,6 +345,17 @@ private void tryAllHandlers(final RestRequest request, final RestChannel channel
                        BytesRestResponse.
                            createSimpleErrorResponse(channel, BAD_REQUEST, "multiple values for single-valued header [" + name + "]."));
                    return;
+                } else if (name.equals(Task.TRACE_PARENT)) {


Do you think we could extract the whole headers copy to a separate method?

pgomulka · 2021-06-18T09:39:28Z

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

-            ThreadContextStruct threadContextStruct =
-                DEFAULT_CONTEXT.putHeaders(Map.of(Task.X_OPAQUE_ID, context.requestHeaders.get(Task.X_OPAQUE_ID)));
+
+        if (context.requestHeaders.containsKey(Task.X_OPAQUE_ID) || context.requestHeaders.containsKey(Task.TRACE_PARENT)) {


Do we also need for TRACE_ID ?

I don't think so as TRACE_ID a transient header. It's not getting in our out of a single node. It's just used for log correlation.

…ThreadContext.java Co-authored-by: Felix Barnsteiner <felixbarny@users.noreply.github.com>

felixbarny · 2021-06-18T09:56:43Z

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

-            ThreadContextStruct threadContextStruct =
-                DEFAULT_CONTEXT.putHeaders(Map.of(Task.X_OPAQUE_ID, context.requestHeaders.get(Task.X_OPAQUE_ID)));
+
+        if (context.requestHeaders.containsKey(Task.X_OPAQUE_ID) || context.requestHeaders.containsKey(Task.TRACE_PARENT)) {


I don't think so as TRACE_ID a transient header. It's not getting in our out of a single node. It's just used for log correlation.

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

Mpdreamz · 2021-06-18T10:43:15Z

looks good!
can we also add testing in JsonLoggerTests ?

Will do! 😸

I am not sure what is the difference for trace_parent and trace_id ?

trace_parent refers to the whole header, trace_id refers to the parsed trace_id portion inside the header.
See the specification for naming: https://www.w3.org/TR/trace-context/#traceparent-header

Co-authored-by: Felix Barnsteiner <felixbarny@users.noreply.github.com>

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

…ticsearch into Mpdreamz-feature/trace-header

…transient header

…trace-header

felixbarny · 2021-06-21T11:32:11Z

@pgomulka will the trace.id be added to the ECS JSON logs only or also to plain-text logs?
IIRC, plain-text is the default in 7.x and ECS JSON is the default in master/8.0, right?

pgomulka · 2021-06-21T11:47:20Z

@pgomulka will the trace.id be added to the ECS JSON logs only or also to plain-text logs?
IIRC, plain-text is the default in 7.x and ECS JSON is the default in master/8.0, right?

@felixbarny
Both ES8 and ES7 emit plaintext logs. ES7 also emits JSON logs, but not in ECS schema
ES8 emits JSON logs in ECS schema

the sample log line for ES8 will be

{
  "@timestamp": "2021-06-21T11:44:05.345Z",
  "log.level": "INFO",
  "message": "[my_index4] creating index, cause [auto(bulk api)], templates [], shards [1]/[1]",
  "service.name": "ES_ECS",
  "process.thread.name": "elasticsearch[runTask-0][masterService#updateTask][T#1]",
  "log.logger": "org.elasticsearch.cluster.metadata.MetadataCreateIndexService",
  "event.dataset": "elasticsearch.server",
  "trace.id": "0af7651916cd43dd8448eb211c80319c",
  "elasticsearch.cluster.uuid": "0DXKTcoxQVWTczJONPHTWA",
  "elasticsearch.node.id": "1NGejCPMROaZcMnpQysNIw",
  "elasticsearch.node.name": "runTask-0",
  "elasticsearch.cluster.name": "runTask"
}

and the corresponding plain text log line emitted at the same time

[2021-06-21T13:44:05,345][INFO ][o.e.c.m.MetadataCreateIndexService] [runTask-0] [my_index4] creating index, cause [auto(bulk api)], templates [], shards [1]/[1]

This change is intended to be in v8, right?

pugnascotia · 2021-06-21T14:16:06Z

@pgomulka I skimmed over the diffs, looked reasonable and nothing stood out.

felixbarny · 2021-06-22T09:49:21Z

This change is intended to be in v8, right?

IINM, @mshustov was hoping to get the trace.id in 7.x logs (at least slowlogs) so that there's end-to-end log correlation from Kibana to ES.
I suppose adding the trace.id to 7.x JSON logs wouldn't be too much of a hassle? Plain-text logs might be more tricky as it would also require changes in the log parsing pipelines.

@pgomulka in 8.x, will the default log format be ECS JSON for Elasticsearch? If so, I think it makes sense to do the same in Kibana. WDYT @mshustov?

mshustov · 2021-06-22T12:34:37Z

IINM, @mshustov was hoping to get the trace.id in 7.x logs (at least slowlogs) so that there's end-to-end log correlation from Kibana to ES.

yes. I started talking to the ES team. I will open an issue a bit later.

in 8.x, will the default log format be ECS JSON for Elasticsearch?

Kibana does support ECS JSON format in v8.0, but I've never heard it's going to be the default in Elasticseasrch as of the next major release. @pgomulka Is there an appropriate issue in the Elasticsearch repo? I didn't manage to find one.

Plain-text logs might be more tricky as it would also require changes in the log parsing pipelines.

@pgomulka Kibana and Elasticsearch must align on this behavior. Is the Elasticsearch team going to attach tracing information to the Plain-test logs?

pgomulka · 2021-06-22T12:49:27Z

the default will be ECS JSON format in v8.0. ES will emit .json log files (in ECS) for server, slow logs, deprecated logs. These log files contain additional 'meta data' fields like node ids, cluster names, x-opaque-id and now trace.id.

The purpose of the plaintext (.log) server logs is to be human readable and it only contains the basic fields (timestamp, class, thread, message). Note that only server logs will be in plaintext. All other logs are only in json.

here is an issue #46119
and a PR that makes the JSON logs in ECS and remove the plaintext slow logs/deprecation logs https://github.com/elastic/elasticsearch/pull/47105/files

you should expect these logs to be generated by ESv8

console - > plaintext
my_cluster.log plaintext
my_cluster_server.json (ECS)
my_cluster_audit.json
my_cluster_deprecation.json (ECS)
my_cluster_index_indexing_slowlog.json (ECS)
my_cluster_index_search_slowlog.json (ECS)

@albertzaharovits do you know if we plan to have audit logs in ECS? Do we want trace.id there as well?

This adds just enough support for the traceparent header to be useful in es8. Since Elasticsearch already logs in ECS format extending it with support for transaction.id and trace.id is a quick win. This allows us to surface server/deprecation slow logs from an instrumented application using the Trace Logs feature. Parsing `traceparent` in http layer and populating tasks with `trace_id` which is preserved in thread context.

) (#75331) This adds just enough support for the traceparent header to be useful in es7 Contrary to es8 in 7.x branch the logs are in custom JSON format - not in ECS. trace.id is added to deprecation, slow logs and server JSON logs backport #74210

A new trace.id header is added by elastic#74210. It is handled almost the same way as x-opaque-id. Specifically, it gets passed into default thread context. This means the existing assertion should expect it in addition to x-opaque-id.

A new trace.id header is added by #74210. It is handled almost the same way as x-opaque-id. Specifically, it gets passed into default thread context. This means the existing assertion should expect it in addition to x-opaque-id.

A new trace.id header is added by elastic#74210. It is handled almost the same way as x-opaque-id. Specifically, it gets passed into default thread context. This means the existing assertion should expect it in addition to x-opaque-id.

A new trace.id header is added by #74210. It is handled almost the same way as x-opaque-id. Specifically, it gets passed into default thread context. This means the existing assertion should expect it in addition to x-opaque-id.

since #74210 ES is emitting trace.id into its logs, but it did not emit it into audit logs. This commit adds trace.id into audit logging.

since elastic#74210 ES is emitting trace.id into its logs, but it did not emit it into audit logs. This commit adds trace.id into audit logging.

since #74210 ES is emitting trace.id into its logs, but it did not emit it into audit logs. This commit adds trace.id into audit logging. backport #82849

felixbarny reviewed Jun 17, 2021

View reviewed changes

mshustov mentioned this pull request Jun 17, 2021

Implement Elasticsearch query tracing to a source in Kibana elastic/kibana#101587

Closed

34 tasks

Mpdreamz added 5 commits June 18, 2021 09:14

Adds minimal traceparent header support to Elasticsearch

0064cf4

This makes Elasticsearch accept `traceparent` header and makes sure its available as variable in log4j. By default ECS logger includes it.

update layout

64e20bd

update thread context preservation

ff74038

Introduce trace/transaction id to ECSJsonLayout.java

864d61b

update comments

2ab60f0

matriv added the :Core/Infra/Logging Log management and logging utilities label Jun 18, 2021

elasticmachine added the Team:Core/Infra Meta label for core/infra team label Jun 18, 2021

Remove transaction.id

e3bb235

Mpdreamz force-pushed the feature/trace-header branch from 99c90de to e3bb235 Compare June 18, 2021 07:49

pugnascotia reviewed Jun 18, 2021

View reviewed changes

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java Outdated Show resolved Hide resolved

Update server/src/main/java/org/elasticsearch/common/util/concurrent/…

dc069c0

…ThreadContext.java Co-authored-by: Rory Hunter <pugnascotia@users.noreply.github.com>

felixbarny reviewed Jun 18, 2021

View reviewed changes

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java Outdated Show resolved Hide resolved

pgomulka previously requested changes Jun 18, 2021

View reviewed changes

Update server/src/main/java/org/elasticsearch/common/util/concurrent/…

3771370

…ThreadContext.java Co-authored-by: Felix Barnsteiner <felixbarny@users.noreply.github.com>

felixbarny reviewed Jun 18, 2021

View reviewed changes

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

d3007fa

Co-authored-by: Felix Barnsteiner <felixbarny@users.noreply.github.com>

felixbarny reviewed Jun 18, 2021

View reviewed changes

server/src/main/java/org/elasticsearch/rest/RestController.java Outdated Show resolved Hide resolved

Mpdreamz added 2 commits June 18, 2021 14:58

Extend JsonLoggerTests to include trace.id assertions

70807dd

Removed unused imports

4544fc4

Mpdreamz requested a review from pgomulka June 18, 2021 13:52

pgomulka added 3 commits June 21, 2021 10:20

Merge branch 'feature/trace-header' of git://github.com/Mpdreamz/elas…

dff91d1

…ticsearch into Mpdreamz-feature/trace-header

Store trace_id instead of trace_parent in thread_context. Do not use …

05b1f2e

…transient header

Merge remote-tracking branch 'upstream/master' into Mpdreamz-feature/…

188a6de

…trace-header

javadoc

9bc7a36

pgomulka merged commit c412aae into elastic:master Jun 21, 2021

pgomulka added the v8.0.0 label Jun 21, 2021

pgomulka added the backport pending label Jun 23, 2021

pgomulka mentioned this pull request Jul 14, 2021

Adds minimal traceparent header support to Elasticsearch backport(#74210) #75331

Merged

pgomulka added the v7.15.0 label Jul 14, 2021

axw mentioned this pull request Jul 16, 2021

apmelasticsearch: send traceparent header to Elasticsearch elastic/apm-agent-go#987

Closed

jakelandis added v8.0.0-alpha1 and removed v8.0.0 labels Jul 26, 2021

ywangd mentioned this pull request Aug 4, 2021

[Test] Allow trace.id in default thread context. #76089

Merged

joegallo added >enhancement and removed backport pending labels Sep 22, 2021

This was referenced Jan 20, 2022

X-Opaque-ID contains UUID causing ES deduplication to fail elastic/kibana#120124

Closed

Emit trace.id into audit logs #82849

Merged

pgomulka added a commit that referenced this pull request Jan 25, 2022

Emit trace.id into audit logs (#82849)

533f6e0

since #74210 ES is emitting trace.id into its logs, but it did not emit it into audit logs. This commit adds trace.id into audit logging.

pgomulka mentioned this pull request Jan 25, 2022

[7.17] Emit trace.id into audit logs backport(#82849) #83031

Merged

pgomulka added a commit that referenced this pull request Jan 25, 2022

[7.17[ Emit trace.id into audit logs (#82849) (#83031)

b4f17d4

since #74210 ES is emitting trace.id into its logs, but it did not emit it into audit logs. This commit adds trace.id into audit logging. backport #82849

pgayvallet mentioned this pull request Jan 25, 2022

Stop Kibana from generating unique X-Opaque-ID values when not received from the client. elastic/kibana#123737

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Adds minimal traceparent header support to Elasticsearch #74210

Adds minimal traceparent header support to Elasticsearch #74210

Mpdreamz commented Jun 16, 2021 •

edited

Loading

felixbarny Jun 17, 2021

felixbarny Jun 17, 2021

Mpdreamz Jun 17, 2021

felixbarny Jun 18, 2021

Mpdreamz Jun 18, 2021

elasticmachine commented Jun 18, 2021

pgomulka left a comment

pgomulka Jun 18, 2021

pgomulka Jun 18, 2021

felixbarny Jun 18, 2021 •

edited

Loading

felixbarny Jun 18, 2021 •

edited

Loading

Mpdreamz commented Jun 18, 2021 •

edited

Loading

felixbarny commented Jun 21, 2021

pgomulka commented Jun 21, 2021 •

edited

Loading

pugnascotia commented Jun 21, 2021

felixbarny commented Jun 22, 2021

mshustov commented Jun 22, 2021 •

edited

Loading

pgomulka commented Jun 22, 2021 •

edited

Loading

		String[] tokens = traceparent.split("-");
		if (tokens.length == 4) {

Adds minimal traceparent header support to Elasticsearch #74210

Adds minimal traceparent header support to Elasticsearch #74210

Conversation

Mpdreamz commented Jun 16, 2021 • edited Loading

felixbarny Jun 17, 2021

Choose a reason for hiding this comment

felixbarny Jun 17, 2021

Choose a reason for hiding this comment

Mpdreamz Jun 17, 2021

Choose a reason for hiding this comment

felixbarny Jun 18, 2021

Choose a reason for hiding this comment

Mpdreamz Jun 18, 2021

Choose a reason for hiding this comment

elasticmachine commented Jun 18, 2021

pgomulka left a comment

Choose a reason for hiding this comment

pgomulka Jun 18, 2021

Choose a reason for hiding this comment

pgomulka Jun 18, 2021

Choose a reason for hiding this comment

felixbarny Jun 18, 2021 • edited Loading

Choose a reason for hiding this comment

felixbarny Jun 18, 2021 • edited Loading

Choose a reason for hiding this comment

Mpdreamz commented Jun 18, 2021 • edited Loading

felixbarny commented Jun 21, 2021

pgomulka commented Jun 21, 2021 • edited Loading

pugnascotia commented Jun 21, 2021

felixbarny commented Jun 22, 2021

mshustov commented Jun 22, 2021 • edited Loading

pgomulka commented Jun 22, 2021 • edited Loading

Mpdreamz commented Jun 16, 2021 •

edited

Loading

felixbarny Jun 18, 2021 •

edited

Loading

felixbarny Jun 18, 2021 •

edited

Loading

Mpdreamz commented Jun 18, 2021 •

edited

Loading

pgomulka commented Jun 21, 2021 •

edited

Loading

mshustov commented Jun 22, 2021 •

edited

Loading

pgomulka commented Jun 22, 2021 •

edited

Loading