Elasticsearch 8.x JSON logs do not always include an "ecs.version" field

[trentm]

Elasticsearch version (bin/elasticsearch --version):

(I am running ES via https://github.com/elastic/apm-integration-testing/#readme)

~ $ ./bin/elasticsearch --version
Version: 8.0.0-SNAPSHOT, Build: default/docker/f273bcf422e16da814774c5bd39194ec8b9735c8/2021-05-19T13:39:24.219172599Z, JVM: 16.0.1

Plugins installed: []

JVM version (java -version):

~ $ ps
PID   USER     TIME  COMMAND
    1 elastics  0:00 /bin/tini -- /usr/local/bin/docker-entrypoint.sh eswrapper
    8 elastics  1:10 /usr/share/elasticsearch/jdk/bin/java -Xshare:auto -Des.networkaddress.cache.ttl=60 -Des.networkaddress.cache.negative.ttl=10 -XX:+AlwaysPreTouch
  236 elastics  0:00 /usr/share/elasticsearch/modules/x-pack-ml/platform/linux-x86_64/bin/controller
  490 elastics  0:00 /bin/sh
  698 elastics  0:00 ps
~ $ /usr/share/elasticsearch/jdk/bin/java -version
openjdk version "16.0.1" 2021-04-20
OpenJDK Runtime Environment AdoptOpenJDK-16.0.1+9 (build 16.0.1+9)
OpenJDK 64-Bit Server VM AdoptOpenJDK-16.0.1+9 (build 16.0.1+9, mixed mode, sharing)

OS version (uname -a if on a Unix-like system):

~ $ uname -a
Linux a538ab651c66 5.10.25-linuxkit #1 SMP Tue Mar 23 09:27:39 UTC 2021 x86_64 GNU/Linux

Description of the problem including expected versus actual behavior:

In #47105 JSON logs were made "ECS compliant". However, I notice that only some of the log records include an ecs.version field that, according to the ecs-logging spec, is required.

For example, only the second of these five log records include "ecs.version"

{"@timestamp":"2021-04-08T16:22:52.257Z", "log.level": "INFO", "message":"adding index lifecycle policy [apm-rollover-30-days]", "service.name":"ES_ECS","process.thread.name":"elasticsearch[01f5411cc2d6][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.xpack.ilm.action.TransportPutLifecycleAction","event.dataset":"elasticsearch.server","elasticsearch.cluster.uuid":"wMGQhNeoRKO0HO0TdVWqtw","elasticsearch.node.id":"-A230e5wSk6Pubf3TrFhzw","elasticsearch.node.name":"01f5411cc2d6","elasticsearch.cluster.name":"docker-cluster"}
{"@timestamp":"2021-04-08T16:22:52.296Z", "log.level": "INFO", "message":"adding template [apm-8.0.0-metric] for index patterns [apm-8.0.0-metric*]", "service.name":"ES_ECS","process.thread.name":"elasticsearch[01f5411cc2d6][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataIndexTemplateService","event.dataset":"elasticsearch.server","elasticsearch.cluster.uuid":"wMGQhNeoRKO0HO0TdVWqtw","elasticsearch.node.id":"-A230e5wSk6Pubf3TrFhzw","elasticsearch.node.name":"01f5411cc2d6","elasticsearch.cluster.name":"docker-cluster"}
{"@timestamp":"2021-04-08T16:22:52.326Z", "log.level":"DEPRECATION",  "data_stream.dataset":"elasticsearch.deprecation", "data_stream.namespace":"default", "data_stream.type":"logs", "ecs.version":"1.7", "elasticsearch.event.category":"templates", "event.code":"index_template_multiple_match", "message":"index [apm-8.0.0-metric-000001] matches multiple legacy templates [apm-8.0.0, apm-8.0.0-metric], composable templates will only match a single template" , "service.name":"ES_ECS","process.thread.name":"elasticsearch[01f5411cc2d6][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.deprecation.cluster.metadata.MetadataCreateIndexService","event.dataset":"elasticsearch.deprecation","elasticsearch.cluster.uuid":"wMGQhNeoRKO0HO0TdVWqtw","elasticsearch.node.id":"-A230e5wSk6Pubf3TrFhzw","elasticsearch.node.name":"01f5411cc2d6","elasticsearch.cluster.name":"docker-cluster"}
{"@timestamp":"2021-04-08T16:22:52.344Z", "log.level": "INFO", "message":"[apm-8.0.0-metric-000001] creating index, cause [api], templates [apm-8.0.0-metric, apm-8.0.0], shards [1]/[0]", "service.name":"ES_ECS","process.thread.name":"elasticsearch[01f5411cc2d6][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataCreateIndexService","event.dataset":"elasticsearch.server","elasticsearch.cluster.uuid":"wMGQhNeoRKO0HO0TdVWqtw","elasticsearch.node.id":"-A230e5wSk6Pubf3TrFhzw","elasticsearch.node.name":"01f5411cc2d6","elasticsearch.cluster.name":"docker-cluster"}
{"@timestamp":"2021-04-08T16:22:52.399Z", "log.level": "INFO", "message":"moving index [apm-8.0.0-metric-000001] from [null] to [{\"phase\":\"new\",\"action\":\"complete\",\"name\":\"complete\"}] in policy [apm-rollover-30-days]", "service.name":"ES_ECS","process.thread.name":"elasticsearch[01f5411cc2d6][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.xpack.ilm.IndexLifecycleTransition","event.dataset":"elasticsearch.server","elasticsearch.cluster.uuid":"wMGQhNeoRKO0HO0TdVWqtw","elasticsearch.node.id":"-A230e5wSk6Pubf3TrFhzw","elasticsearch.node.name":"01f5411cc2d6","elasticsearch.cluster.name":"docker-cluster"}

I would expect all the ECS format log records to include "ecs.version". I'm curious whether this should be considered an ES bug, and/or whether the ecs-logging spec should consider relaxing that required field.

The specific issue for me is with an ecslog tool (issue) that I have written to pretty-print and filter ecs-logging format logs. Currently ecslog skips JSON lines that don't meet the minimum requirements in the ecs-logging spec, so most logs from ES are not rendered or filterable with this tool.

(/cc @felixbarny)

Steps to reproduce:

Run an Elasticsearch 8.x build that has its appender.console.layout.type in "config/log4j.properties" set to use ECSJsonLayout. For example:

1. Build the latest ES from the master branch.
2. Make this log4j.properties change:

% diff -u build/distribution/local/elasticsearch-8.0.0-SNAPSHOT/config/log4j2.properties.orig build/distribution/local/elasticsearch-8.0.0-SNAPSHOT/config/log4j2.properties
--- build/distribution/local/elasticsearch-8.0.0-SNAPSHOT/config/log4j2.properties.orig	2021-05-19 14:02:16.000000000 -0700
+++ build/distribution/local/elasticsearch-8.0.0-SNAPSHOT/config/log4j2.properties	2021-05-19 14:16:20.000000000 -0700
@@ -2,8 +2,8 @@

appender.console.type = Console
appender.console.name = console
-appender.console.layout.type = PatternLayout
-appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
+appender.console.layout.type = ECSJsonLayout
+appender.console.layout.dataset = elasticsearch.server

######## Server JSON ############################
appender.rolling.type = RollingFile

3. Run ES: build/distribution/local/elasticsearch-8.0.0-SNAPSHOT/bin/elasticsearch

[elasticmachine]

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

[pgomulka]

In fact, I cannot see any ecs.version in elasticsearch_server.json log file.
We don't populate that field in ES (apart from deprecation log, which I guess we should not)
We rely on https://github.com/elastic/ecs-logging-java to populate necessary fields.
The version ecs logging java is 0.1.3. I can see https://github.com/elastic/ecs-logging-java/blame/09c07cf451bebb86f82e3f21abc0579455d81ee8/ecs-logging-core/src/main/java/co/elastic/logging/EcsJsonSerializer.java#L51 that with latest version this should be fixed.
I will work on upgrading the library in ES

[rjernst]

It looks like this should already be addressed by previous upgrading of the ecs-logging-java library.