Add drop and explicit tests to avoid duplicate ingest of elasticsearc…

…h logs (#30440) (#30488)

* Ensure we drop server logs that show up in deprecation pipeline

* Add note about deprecation dataset normalization

* Add test for mixed es server logs

This pipeline already contained a drop to avoid duplicate logging.

* Ensure we drop server logs that show up in slowlog pipeline

This was partially guarded against in testing due to the grok on `elasticsearch.slowlog` but probably better to explicitly drop and avoid duplicate logging.

* Add "mixed" test for elasticsearch audit logs

test-audit-docker.log also contains a case but it was overlooked in the expected file until #30164 added the appropriate drop statements.

* Changelog entry

* Remove duplicatd filebeat header

(cherry picked from commit 7b67384)

Co-authored-by: Mat Schaffer <[email protected]>

CHANGELOG.next.asciidoc

@@ -53,6 +53,7 @@ https://github.com/elastic/beats/compare/v7.0.0-alpha2...master[Check the HEAD d
 *Filebeat*
 - Fix broken Kafka input {issue}29746[29746] {pull}30277[30277]
 - auditd: Prevent mapping explosion when truncated EXECVE records are ingested. {pull}30382[30382]
+- elasticsearch: fix duplicate ingest when using a common appender configuration {issue}30428[30428] {pull}30440[30440]
 
 
 *Heartbeat*

filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log

@@ -0,0 +1,2 @@
+{"type":"audit", "timestamp":"2022-01-27T14:16:25,271+0100", "node.id":"O8SFUsk8QpGG16JVJcNgUw", "event.type":"transport", "event.action":"access_granted", "authentication.type":"REALM", "user.name":"elastic", "user.realm":"reserved", "user.roles":["superuser"], "origin.type":"rest", "origin.address":"[::1]:64583", "request.id":"yEUG-8deS2y8ZxGgeyeUnw", "action":"indices:admin/create", "request.name":"CreateIndexRequest", "indices":["test_1"], "opaque_id":"myApp1", "trace.id":"0af7651916cd43dd8448eb211c80319c"}
+{"@timestamp":"2022-01-25T15:12:08.686Z", "log.level": "INFO", "message":"adding template [.monitoring-alerts-7] for index patterns [.monitoring-alerts-7]", "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.server","process.thread.name":"elasticsearch[matschaffer-mbp2019.lan][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataIndexTemplateService","elasticsearch.cluster.uuid":"28iKoFsvTJ6HEyXbdLL-PQ","elasticsearch.node.id":"tc3nhgC0SFCKfwwy6jCmkw","elasticsearch.node.name":"matschaffer-mbp2019.lan","elasticsearch.cluster.name":"main"}

filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log-expected.json

@@ -0,0 +1,41 @@
+[
+    {
+        "@timestamp": "2022-01-27T13:16:25.271Z",
+        "elasticsearch.audit.action": "indices:admin/create",
+        "elasticsearch.audit.authentication.type": "REALM",
+        "elasticsearch.audit.indices": [
+            "test_1"
+        ],
+        "elasticsearch.audit.layer": "transport",
+        "elasticsearch.audit.opaque_id": "myApp1",
+        "elasticsearch.audit.origin.type": "rest",
+        "elasticsearch.audit.request.id": "yEUG-8deS2y8ZxGgeyeUnw",
+        "elasticsearch.audit.request.name": "CreateIndexRequest",
+        "elasticsearch.audit.user.realm": "reserved",
+        "elasticsearch.audit.user.roles": [
+            "superuser"
+        ],
+        "elasticsearch.node.id": "O8SFUsk8QpGG16JVJcNgUw",
+        "event.action": "access_granted",
+        "event.category": "database",
+        "event.dataset": "elasticsearch.audit",
+        "event.kind": "event",
+        "event.module": "elasticsearch",
+        "event.outcome": "success",
+        "fileset.name": "audit",
+        "host.id": "O8SFUsk8QpGG16JVJcNgUw",
+        "http.request.id": "yEUG-8deS2y8ZxGgeyeUnw",
+        "input.type": "log",
+        "log.offset": 0,
+        "message": "{\"type\":\"audit\", \"timestamp\":\"2022-01-27T14:16:25,271+0100\", \"node.id\":\"O8SFUsk8QpGG16JVJcNgUw\", \"event.type\":\"transport\", \"event.action\":\"access_granted\", \"authentication.type\":\"REALM\", \"user.name\":\"elastic\", \"user.realm\":\"reserved\", \"user.roles\":[\"superuser\"], \"origin.type\":\"rest\", \"origin.address\":\"[::1]:64583\", \"request.id\":\"yEUG-8deS2y8ZxGgeyeUnw\", \"action\":\"indices:admin/create\", \"request.name\":\"CreateIndexRequest\", \"indices\":[\"test_1\"], \"opaque_id\":\"myApp1\", \"trace.id\":\"0af7651916cd43dd8448eb211c80319c\"}",
+        "related.user": [
+            "elastic"
+        ],
+        "service.type": "elasticsearch",
+        "source.address": "[::1]:64583",
+        "source.ip": "::1",
+        "source.port": 64583,
+        "trace.id": "0af7651916cd43dd8448eb211c80319c",
+        "user.name": "elastic"
+    }
+]

filebeat/module/elasticsearch/deprecation/ingest/pipeline-json-8.yml

@@ -10,6 +10,10 @@ processors:
 - dot_expander:
     field: '*'
     override: true
+# Drop any non-deprecation logs that show up due to mixed log output configurations
+- drop:
+    if: '!["deprecation", "deprecation.elasticsearch"].contains(ctx.event.dataset)'
+# Normalize event.dataset value for kibana queries
 - set:
     field: event.dataset
     value: elasticsearch.deprecation

filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log

@@ -0,0 +1,2 @@
+{"@timestamp":"2022-01-27T11:48:45.809Z", "log.level":"CRITICAL",  "data_stream.dataset":"deprecation.elasticsearch","data_stream.namespace":"default","data_stream.type":"logs","elasticsearch.elastic_product_origin":"","elasticsearch.event.category":"compatible_api","elasticsearch.http.request.x_opaque_id":"v7app","event.code":"create_index_with_types","message":"[types removal] Using include_type_name in create index requests is deprecated. The parameter will be removed in the next major version." , "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"deprecation.elasticsearch","process.thread.name":"elasticsearch[runTask-0][transport_worker][T#8]","log.logger":"org.elasticsearch.deprecation.rest.action.admin.indices.RestCreateIndexAction","trace.id":"0af7651916cd43dd8448eb211c80319c","elasticsearch.cluster.uuid":"5alW33KLT16Lp1SevDqDSQ","elasticsearch.node.id":"tVLnAGLgQum5ca6z50aqbw","elasticsearch.node.name":"runTask-0","elasticsearch.cluster.name":"runTask"}
+{"@timestamp":"2022-01-25T15:12:08.686Z", "log.level": "INFO", "message":"adding template [.monitoring-alerts-7] for index patterns [.monitoring-alerts-7]", "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.server","process.thread.name":"elasticsearch[matschaffer-mbp2019.lan][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataIndexTemplateService","elasticsearch.cluster.uuid":"28iKoFsvTJ6HEyXbdLL-PQ","elasticsearch.node.id":"tc3nhgC0SFCKfwwy6jCmkw","elasticsearch.node.name":"matschaffer-mbp2019.lan","elasticsearch.cluster.name":"main"}

filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log-expected.json

@@ -0,0 +1,32 @@
+[
+    {
+        "@timestamp": "2022-01-27T11:48:45.809Z",
+        "data_stream.dataset": "deprecation.elasticsearch",
+        "data_stream.namespace": "default",
+        "data_stream.type": "logs",
+        "elasticsearch.cluster.name": "runTask",
+        "elasticsearch.cluster.uuid": "5alW33KLT16Lp1SevDqDSQ",
+        "elasticsearch.elastic_product_origin": "",
+        "elasticsearch.event.category": "compatible_api",
+        "elasticsearch.http.request.x_opaque_id": "v7app",
+        "elasticsearch.node.id": "tVLnAGLgQum5ca6z50aqbw",
+        "elasticsearch.node.name": "runTask-0",
+        "event.category": "database",
+        "event.code": "create_index_with_types",
+        "event.dataset": "elasticsearch.deprecation",
+        "event.kind": "event",
+        "event.module": "elasticsearch",
+        "event.type": "info",
+        "fileset.name": "deprecation",
+        "host.id": "tVLnAGLgQum5ca6z50aqbw",
+        "input.type": "log",
+        "log.level": "CRITICAL",
+        "log.logger": "org.elasticsearch.deprecation.rest.action.admin.indices.RestCreateIndexAction",
+        "log.offset": 0,
+        "message": "[types removal] Using include_type_name in create index requests is deprecated. The parameter will be removed in the next major version.",
+        "process.thread.name": "elasticsearch[runTask-0][transport_worker][T#8]",
+        "service.name": "ES_ECS",
+        "service.type": "elasticsearch",
+        "trace.id": "0af7651916cd43dd8448eb211c80319c"
+    }
+]

filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log

@@ -0,0 +1,2 @@
+{"@timestamp":"2022-01-25T15:12:08.472Z", "log.level": "INFO", "message":"adding template [.monitoring-kibana] for index patterns [.monitoring-kibana-7-*]", "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.server","process.thread.name":"elasticsearch[matschaffer-mbp2019.lan][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataIndexTemplateService","elasticsearch.cluster.uuid":"28iKoFsvTJ6HEyXbdLL-PQ","elasticsearch.node.id":"tc3nhgC0SFCKfwwy6jCmkw","elasticsearch.node.name":"matschaffer-mbp2019.lan","elasticsearch.cluster.name":"main"}
+{"@timestamp":"2022-01-27T11:48:45.809Z", "log.level":"CRITICAL",  "data_stream.dataset":"deprecation.elasticsearch","data_stream.namespace":"default","data_stream.type":"logs","elasticsearch.elastic_product_origin":"","elasticsearch.event.category":"compatible_api","elasticsearch.http.request.x_opaque_id":"v7app","event.code":"create_index_with_types","message":"[types removal] Using include_type_name in create index requests is deprecated. The parameter will be removed in the next major version." , "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"deprecation.elasticsearch","process.thread.name":"elasticsearch[runTask-0][transport_worker][T#8]","log.logger":"org.elasticsearch.deprecation.rest.action.admin.indices.RestCreateIndexAction","trace.id":"0af7651916cd43dd8448eb211c80319c","elasticsearch.cluster.uuid":"5alW33KLT16Lp1SevDqDSQ","elasticsearch.node.id":"tVLnAGLgQum5ca6z50aqbw","elasticsearch.node.name":"runTask-0","elasticsearch.cluster.name":"runTask"}

filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log-expected.json

@@ -0,0 +1,24 @@
+[
+    {
+        "@timestamp": "2022-01-25T15:12:08.472Z",
+        "elasticsearch.cluster.name": "main",
+        "elasticsearch.cluster.uuid": "28iKoFsvTJ6HEyXbdLL-PQ",
+        "elasticsearch.node.id": "tc3nhgC0SFCKfwwy6jCmkw",
+        "elasticsearch.node.name": "matschaffer-mbp2019.lan",
+        "event.category": "database",
+        "event.dataset": "elasticsearch.server",
+        "event.kind": "event",
+        "event.module": "elasticsearch",
+        "event.type": "info",
+        "fileset.name": "server",
+        "host.id": "tc3nhgC0SFCKfwwy6jCmkw",
+        "input.type": "log",
+        "log.level": "INFO",
+        "log.logger": "org.elasticsearch.cluster.metadata.MetadataIndexTemplateService",
+        "log.offset": 0,
+        "message": "adding template [.monitoring-kibana] for index patterns [.monitoring-kibana-7-*]",
+        "process.thread.name": "elasticsearch[matschaffer-mbp2019.lan][masterService#updateTask][T#1]",
+        "service.name": "ES_ECS",
+        "service.type": "elasticsearch"
+    }
+]

filebeat/module/elasticsearch/slowlog/ingest/pipeline-json-8.yml

@@ -10,6 +10,9 @@ processors:
 - dot_expander:
     field: '*'
     override: true
+# Drop any non-slowlog messages that show up due to mixed log output configurations
+- drop:
+    if: '!["elasticsearch.slowlog", "elasticsearch.index_indexing_slowlog", "elasticsearch.index_search_slowlog"].contains(ctx.event.dataset)'
 - convert:
     field: elasticsearch.slowlog.took_millis
     type: float

filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log

@@ -0,0 +1,3 @@
+{"@timestamp":"2022-01-25T15:12:08.686Z", "log.level": "INFO", "message":"adding template [.monitoring-alerts-7] for index patterns [.monitoring-alerts-7]", "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.server","process.thread.name":"elasticsearch[matschaffer-mbp2019.lan][masterService#updateTask][T#1]","log.logger":"org.elasticsearch.cluster.metadata.MetadataIndexTemplateService","elasticsearch.cluster.uuid":"28iKoFsvTJ6HEyXbdLL-PQ","elasticsearch.node.id":"tc3nhgC0SFCKfwwy6jCmkw","elasticsearch.node.name":"matschaffer-mbp2019.lan","elasticsearch.cluster.name":"main"}
+{"@timestamp":"2022-01-27T11:39:29.508Z", "log.level":"TRACE",  "elasticsearch.slowlog.id":"_oRVm34B7FprLQsjW_Zh","elasticsearch.slowlog.message":"[test_1/8pT6xiN_Tt-dcJWRR3LX6A]","elasticsearch.slowlog.source":"{\\\"a\\\":","elasticsearch.slowlog.took":"1.7ms","elasticsearch.slowlog.took_millis":"1" , "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.index_indexing_slowlog","process.thread.name":"elasticsearch[runTask-0][write][T#5]","log.logger":"index.indexing.slowlog.index","trace.id":"0af7651916cd43dd8448eb211c80319c","elasticsearch.cluster.uuid":"5alW33KLT16Lp1SevDqDSQ","elasticsearch.node.id":"tVLnAGLgQum5ca6z50aqbw","elasticsearch.node.name":"runTask-0","elasticsearch.cluster.name":"runTask"}
+{"@timestamp":"2022-01-27T11:42:31.395Z", "log.level":"DEBUG",  "elasticsearch.slowlog.id":null,"elasticsearch.slowlog.message":"[test_1][0]","elasticsearch.slowlog.search_type":"QUERY_THEN_FETCH","elasticsearch.slowlog.source":"{}","elasticsearch.slowlog.stats":"[]","elasticsearch.slowlog.took":"115.3micros","elasticsearch.slowlog.took_millis":0,"elasticsearch.slowlog.total_hits":"2 hits","elasticsearch.slowlog.total_shards":1 , "ecs.version": "1.2.0","service.name":"ES_ECS","event.dataset":"elasticsearch.index_search_slowlog","process.thread.name":"elasticsearch[runTask-0][search][T#5]","log.logger":"index.search.slowlog.query","elasticsearch.cluster.uuid":"5alW33KLT16Lp1SevDqDSQ","elasticsearch.node.id":"tVLnAGLgQum5ca6z50aqbw","elasticsearch.node.name":"runTask-0","elasticsearch.cluster.name":"runTask"}

filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log-expected.json

@@ -0,0 +1,63 @@
+[
+    {
+        "@timestamp": "2022-01-27T11:39:29.508Z",
+        "elasticsearch.cluster.name": "runTask",
+        "elasticsearch.cluster.uuid": "5alW33KLT16Lp1SevDqDSQ",
+        "elasticsearch.index.id": "8pT6xiN_Tt-dcJWRR3LX6A",
+        "elasticsearch.index.name": "test_1",
+        "elasticsearch.node.id": "tVLnAGLgQum5ca6z50aqbw",
+        "elasticsearch.node.name": "runTask-0",
+        "elasticsearch.slowlog.id": "_oRVm34B7FprLQsjW_Zh",
+        "elasticsearch.slowlog.source": "{\\\"a\\\":",
+        "elasticsearch.slowlog.took": "1.7ms",
+        "event.category": "database",
+        "event.dataset": "elasticsearch.index_indexing_slowlog",
+        "event.duration": 1000000,
+        "event.kind": "event",
+        "event.module": "elasticsearch",
+        "event.type": "info",
+        "fileset.name": "slowlog",
+        "host.id": "tVLnAGLgQum5ca6z50aqbw",
+        "input.type": "log",
+        "log.level": "TRACE",
+        "log.logger": "index.indexing.slowlog.index",
+        "log.offset": 608,
+        "message": "[test_1/8pT6xiN_Tt-dcJWRR3LX6A]",
+        "process.thread.name": "elasticsearch[runTask-0][write][T#5]",
+        "service.name": "ES_ECS",
+        "service.type": "elasticsearch",
+        "trace.id": "0af7651916cd43dd8448eb211c80319c"
+    },
+    {
+        "@timestamp": "2022-01-27T11:42:31.395Z",
+        "elasticsearch.cluster.name": "runTask",
+        "elasticsearch.cluster.uuid": "5alW33KLT16Lp1SevDqDSQ",
+        "elasticsearch.index.name": "test_1",
+        "elasticsearch.node.id": "tVLnAGLgQum5ca6z50aqbw",
+        "elasticsearch.node.name": "runTask-0",
+        "elasticsearch.shard.id": "0",
+        "elasticsearch.slowlog.id": null,
+        "elasticsearch.slowlog.search_type": "QUERY_THEN_FETCH",
+        "elasticsearch.slowlog.source": "{}",
+        "elasticsearch.slowlog.stats": "[]",
+        "elasticsearch.slowlog.took": "115.3micros",
+        "elasticsearch.slowlog.total_hits": "2 hits",
+        "elasticsearch.slowlog.total_shards": 1,
+        "event.category": "database",
+        "event.dataset": "elasticsearch.index_search_slowlog",
+        "event.duration": 0,
+        "event.kind": "event",
+        "event.module": "elasticsearch",
+        "event.type": "info",
+        "fileset.name": "slowlog",
+        "host.id": "tVLnAGLgQum5ca6z50aqbw",
+        "input.type": "log",
+        "log.level": "DEBUG",
+        "log.logger": "index.search.slowlog.query",
+        "log.offset": 1346,
+        "message": "[test_1][0]",
+        "process.thread.name": "elasticsearch[runTask-0][search][T#5]",
+        "service.name": "ES_ECS",
+        "service.type": "elasticsearch"
+    }
+]