From 309cf638151f9f219b88d007f77637f2a389210b Mon Sep 17 00:00:00 2001 From: Mat Schaffer Date: Mon, 21 Feb 2022 12:10:22 +0900 Subject: [PATCH] Add drop and explicit tests to avoid duplicate ingest of elasticsearch logs (#30440) * 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 https://github.com/elastic/beats/pull/30164 added the appropriate drop statements. * Changelog entry * Remove duplicatd filebeat header (cherry picked from commit 7b67384954718e9f59a39549f741a2156396679f) --- CHANGELOG.next.asciidoc | 1 + .../audit/test/test-audit-800.mixed.log | 2 + .../test-audit-800.mixed.log-expected.json | 41 ++++++++++++ .../deprecation/ingest/pipeline-json-8.yml | 4 ++ .../test/es_deprecation-json.800.mixed.log | 2 + ...precation-json.800.mixed.log-expected.json | 32 ++++++++++ .../test/elasticsearch-json.800.mixed.log | 2 + ...ticsearch-json.800.mixed.log-expected.json | 24 +++++++ .../slowlog/ingest/pipeline-json-8.yml | 3 + .../slowlog/test/es_slowlog.800.mixed.log | 3 + .../es_slowlog.800.mixed.log-expected.json | 63 +++++++++++++++++++ 11 files changed, 177 insertions(+) create mode 100644 filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log create mode 100644 filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log-expected.json create mode 100644 filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log create mode 100644 filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log-expected.json create mode 100644 filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log create mode 100644 filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log-expected.json create mode 100644 filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log create mode 100644 filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log-expected.json diff --git a/CHANGELOG.next.asciidoc b/CHANGELOG.next.asciidoc index e0c54f76fbb..3c1c4c11798 100644 --- a/CHANGELOG.next.asciidoc +++ b/CHANGELOG.next.asciidoc @@ -52,6 +52,7 @@ https://github.com/elastic/beats/compare/v7.0.0-alpha2...master[Check the HEAD d - cisco module: Fix change the broke ASA and FTD configs that used `var.input: syslog`. {pull}30072[30072] - aws-s3: fix race condition in states used by s3-poller. {issue}30123[30123] {pull}30131[30131] - 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* - Fix missing mapping for `service.name`. {pull}30324[30324] diff --git a/filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log b/filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log new file mode 100644 index 00000000000..ea47c05004b --- /dev/null +++ b/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"} diff --git a/filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log-expected.json b/filebeat/module/elasticsearch/audit/test/test-audit-800.mixed.log-expected.json new file mode 100644 index 00000000000..b182b67a999 --- /dev/null +++ b/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" + } +] \ No newline at end of file diff --git a/filebeat/module/elasticsearch/deprecation/ingest/pipeline-json-8.yml b/filebeat/module/elasticsearch/deprecation/ingest/pipeline-json-8.yml index 89c7b4083f6..d42697a0e92 100644 --- a/filebeat/module/elasticsearch/deprecation/ingest/pipeline-json-8.yml +++ b/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 diff --git a/filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log b/filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log new file mode 100644 index 00000000000..fa9b17805ee --- /dev/null +++ b/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"} diff --git a/filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log-expected.json b/filebeat/module/elasticsearch/deprecation/test/es_deprecation-json.800.mixed.log-expected.json new file mode 100644 index 00000000000..f3cd1b8c0d4 --- /dev/null +++ b/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" + } +] diff --git a/filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log b/filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log new file mode 100644 index 00000000000..6e4365a9f0c --- /dev/null +++ b/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"} diff --git a/filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log-expected.json b/filebeat/module/elasticsearch/server/test/elasticsearch-json.800.mixed.log-expected.json new file mode 100644 index 00000000000..645f3121652 --- /dev/null +++ b/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" + } +] \ No newline at end of file diff --git a/filebeat/module/elasticsearch/slowlog/ingest/pipeline-json-8.yml b/filebeat/module/elasticsearch/slowlog/ingest/pipeline-json-8.yml index 3e0479d59ea..49f65cbcb8b 100644 --- a/filebeat/module/elasticsearch/slowlog/ingest/pipeline-json-8.yml +++ b/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 diff --git a/filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log b/filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log new file mode 100644 index 00000000000..28e824893fa --- /dev/null +++ b/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"} diff --git a/filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log-expected.json b/filebeat/module/elasticsearch/slowlog/test/es_slowlog.800.mixed.log-expected.json new file mode 100644 index 00000000000..02570cad647 --- /dev/null +++ b/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" + } +] \ No newline at end of file