elastic / beats

:tropical_fish: Beats - Lightweight shippers for Elasticsearch & Logstash
https://www.elastic.co/products/beats
Other
83 stars 4.92k forks source link

[Filebeat] googlecloud module indexing error #18465

Closed SpencerLN closed 4 years ago

SpencerLN commented 4 years ago

While running the Filebeat googlecloud module we noticed an error messaging regarding events failing to be indexed to Elasticsearch in the logs:

2020-05-12T15:01:14.954Z    WARN    elasticsearch/client.go:517 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x3a3bab48, ext:63724892449, loc:(*time.Location)(nil)}, Meta:{"id":"d0bfda02f5-1183688770061909","pipeline":"filebeat-7.6.2-googlecloud-audit-pipeline"}, Fields:{"agent":{"ephemeral_id":"afa01cad-adbd-45cf-98b4-507d4eb62191","hostname":"filebeat-gcp-statefulset-0","id":"2c6e66ca-0d25-430d-b261-da3911e1cab9","type":"filebeat","version":"7.6.2"},"cloud":{"project":{"id":"gcp-project"}},"ecs":{"version":"1.4.0"},"event":{"created":"2020-05-12T15:01:14.049Z","dataset":"googlecloud.audit","id":"d0bfda02f5-1183688770061909","module":"googlecloud","original":"{\"insertId\":\"f1440e02-c072-43b3-a1ef-14699d457c01\",\"labels\":{\"authorization.k8s.io/decision\":\"allow\",\"authorization.k8s.io/reason\":\"RBAC: allowed by ClusterRoleBinding \\\"system:controller:cronjob-controller\\\" of ClusterRole \\\"system:controller:cronjob-controller\\\" to ServiceAccount \\\"cronjob-controller/kube-system\\\"\"},\"logName\":\"projects/gcp-project/logs/cloudaudit.googleapis.com%2Factivity\",\"operation\":{\"first\":true,\"id\":\"f1440e02-c072-43b3-a1ef-14699d457c01\",\"last\":true,\"producer\":\"k8s.io\"},\"protoPayload\":{\"@type\":\"type.googleapis.com/google.cloud.audit.AuditLog\",\"authenticationInfo\":{\"principalEmail\":\"system:serviceaccount:kube-system:cronjob-controller\"},\"authorizationInfo\":[{\"granted\":true,\"permission\":\"io.k8s.batch.v1.jobs.delete\",\"resource\":\"batch/v1/namespaces/default/jobs/gsuite-exporter-1589294700\"}],\"methodName\":\"io.k8s.batch.v1.jobs.delete\",\"request\":{\"@type\":\"batch.k8s.io/v1.DeleteOptions\",\"apiVersion\":\"batch/v1\",\"kind\":\"DeleteOptions\",\"propagationPolicy\":\"Background\"},\"requestMetadata\":{\"callerIp\":\"::1\",\"callerSuppliedUserAgent\":\"kube-controller-manager/v1.14.10 (linux/amd64) kubernetes/145f9e2/system:serviceaccount:kube-system:cronjob-controller\"},\"resourceName\":\"batch/v1/namespaces/default/jobs/gsuite-exporter-1589294700\",\"response\":{\"@type\":\"core.k8s.io/v1.Status\",\"apiVersion\":\"v1\",\"details\":{\"group\":\"batch\",\"kind\":\"jobs\",\"name\":\"gsuite-exporter-1589294700\",\"uid\":\"2beff34a-945f-11ea-bacf-42010a80007f\"},\"kind\":\"Status\",\"metadata\":{},\"status\":\"Success\"},\"serviceName\":\"k8s.io\",\"status\":{}},\"receiveTimestamp\":\"2020-05-12T15:01:13.578169149Z\",\"resource\":{\"labels\":{\"cluster_name\":\"k8s-cluster\",\"location\":\"us-central1-a\",\"project_id\":\"gcp-project\"},\"type\":\"k8s_cluster\"},\"timestamp\":\"2020-05-12T15:00:49.976989Z\"}","outcome":"success"},"fileset":{"name":"audit"},"googlecloud":{"audit":{"authentication_info":{"principal_email":"system:serviceaccount:kube-system:cronjob-controller"},"authorization_info":[{"granted":true,"permission":"io.k8s.batch.v1.jobs.delete","resource":"batch/v1/namespaces/default/jobs/gsuite-exporter-1589294700","resource_attributes":null}],"method_name":"io.k8s.batch.v1.jobs.delete","request":{"apiVersion":"batch/v1","kind":"DeleteOptions","propagationPolicy":"Background","proto_name":"batch.k8s.io/v1.DeleteOptions"},"request_metadata":{"caller_ip":"::1","caller_supplied_user_agent":"kube-controller-manager/v1.14.10 (linux/amd64) kubernetes/145f9e2/system:serviceaccount:kube-system:cronjob-controller"},"resource_name":"batch/v1/namespaces/default/jobs/gsuite-exporter-1589294700","response":{"@type":"core.k8s.io/v1.Status","apiVersion":"v1","details":{"group":"batch","kind":"jobs","name":"gsuite-exporter-1589294700","uid":"2beff34a-945f-11ea-bacf-42010a80007f"},"kind":"Status","metadata":{},"status":"Success"},"service_name":"k8s.io","status":{},"type":"type.googleapis.com/google.cloud.audit.AuditLog"}},"host":{"name":"filebeat-gcp-statefulset-0"},"input":{"type":"google-pubsub"},"labels":{"logging.googleapis.com/timestamp":"2020-05-12T15:00:49.976989Z"},"log":{"logger":"projects/gcp-project/logs/cloudaudit.googleapis.com%2Factivity"},"service":{"name":"k8s.io","type":"googlecloud"},"source":{"ip":"::1"},"user":{"email":"system:serviceaccount:kube-system:cronjob-controller"},"user_agent":{"original":"kube-controller-manager/v1.14.10 (linux/amd64) kubernetes/145f9e2/system:serviceaccount:kube-system:cronjob-controller"}}, Private:(*pubsub.Message)(0xc000a57170), TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:common.MapStr(nil)}} (status=400): {"type":"mapper_parsing_exception","reason":"object mapping for [googlecloud.audit.response.status] tried to parse field [status] as object, but found a concrete value"}

Filebeat templates were installed prior to indexing data and have not been modified.

Configuration:

   filebeat.yml: |-
    filebeat.inputs:
    # Templates are installed via setup job in Epsilon
    setup.template.enabled: false

    filebeat.modules:
    - module: googlecloud
      audit:
        enabled: true
        var.project_id: gcp-project
        var.topic: gcp-audit-logs
        var.subscription_name: audit-log-subscription
        var.credentials_file: /usr/share/filebeat/secrets/credentials.json
        var.keep_original_message: true
      firewall:
        enabled: true
        var.project_id: gcp-project
        var.topic: gcp-firewall-logs
        var.subscription_name: firewall-log-subscription
        var.credentials_file: /usr/share/filebeat/secrets/credentials.json
        var.keep_original_message: true
      vpcflow:
        enabled: true
        var.project_id: gcp-project
        var.topic: gcp-vpcflow-logs
        var.subscription_name: vpcflow-log-subscription
        var.credentials_file: /usr/share/filebeat/secrets/credentials.json
        var.keep_original_message: true

    output.elasticsearch:
        hosts: 'https://${ELASTICSEARCH_ADDRESS}'
        username: ${ELASTICSEARCH_USERNAME}
        password: ${ELASTICSEARCH_PASSWORD}
        ssl:
          enabled: true
          supported_protocols: TLSv1.2 

For confirmed bugs, please report:

elasticmachine commented 4 years ago

Pinging @elastic/siem (Team:SIEM)

alakahakai commented 4 years ago

This problem was caused by some new fields introduced by the response. I am not exactly sure why the field "status" is considered an object since googlecloud.audit module does not define this field under the group "response". I will add the new fields and handle them explicitly. BTW, @SpencerLN Is it possible for you to upload some new raw audit logs, so I can include them in the test file. Thanks!

SpencerLN commented 4 years ago

@alakahakai there may be some concerns with publicly providing raw audit logs due to data sanitization issues. Is there an easy way to retrieve the raw audit logs? These are coming from Pub/Sub, so I am not sure the best way to retrieve them prior to any processing.

alakahakai commented 4 years ago

I see. Not a problem then. I will try to see whether I can get some additional raw data from our test setup. Thanks.

SpencerLN commented 4 years ago

It appears that this issue is still occurring in 7.8.0:

org.elasticsearch.index.mapper.MapperParsingException: object mapping for [googlecloud.audit.response.status] tried to parse field [status] as object, but found a concrete value, at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrNested(DocumentParser.java:377) ~[elasticsearch-7.8.0.jar:7.8.0], at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:485)
andrewkroh commented 4 years ago

Sorry @SpencerLN, this fix was never backported to 7.8.

@alakahakai can you please backport this to 7.8 so that it is included in 7.8.1.

SpencerLN commented 4 years ago

@andrewkroh it looks like this is still occurring in 7.8.1:

2020-08-05T12:09:53.532Z    WARN    [elasticsearch] elasticsearch/client.go:407 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x3af761f8, ext:63732226164, loc:(*time.Location)(nil)}, Meta:{"_id":"d0bfda02f5-1404302606100912","pipeline":"filebeat-7.8.1-googlecloud-audit-pipeline"}, Fields:{"agent":{"ephemeral_id":"d3db6de4-4cea-4605-a09b-ed2fc3fc12c3","hostname":"filebeat-gcp-statefulset-0","id":"2c6e66ca-0d25-430d-b261-da3911e1cab9","name":"filebeat-gcp-statefulset-0","type":"filebeat","version":"7.8.1"},"cloud":{"project":{"id":"gcp-project-name"}},"ecs":{"version":"1.5.0"},"event":{"action":"io.k8s.core.v1.services.update","created":"2020-08-05T12:09:53.145Z","dataset":"googlecloud.audit","id":"d6b423d1-0f49-407e-8a4d-9bacfd580b9d","kind":"event","module":"googlecloud","original":"{\"insertId\":\"d6b423d1-0f49-407e-8a4d-9bacfd580b9d\",\"labels\":{\"authorization.k8s.io/decision\":\"allow\",\"authorization.k8s.io/reason\":\"RBAC: allowed by ClusterRoleBinding \\\"elastic-operator\\\" of ClusterRole \\\"elastic-operator\\\" to ServiceAccount \\\"elastic-operator/elastic-system\\\"\"},\"logName\":\"projects/gcp-project-name/logs/cloudaudit.googleapis.com%2Factivity\",\"operation\":{\"first\":true,\"id\":\"d6b423d1-0f49-407e-8a4d-9bacfd580b9d\",\"last\":true,\"producer\":\"k8s.io\"},\"protoPayload\":{\"@type\":\"type.googleapis.com/google.cloud.audit.AuditLog\",\"authenticationInfo\":{\"principalEmail\":\"system:serviceaccount:elastic-system:elastic-operator\"},\"authorizationInfo\":[{\"granted\":true,\"permission\":\"io.k8s.core.v1.services.update\",\"resource\":\"core/v1/namespaces/default/services/cluster-name-es-transport\"}],\"methodName\":\"io.k8s.core.v1.services.update\",\"request\":{\"@type\":\"core.k8s.io/v1.Service\",\"apiVersion\":\"v1\",\"kind\":\"Service\",\"metadata\":{\"creationTimestamp\":\"2020-05-14T11:16:01Z\",\"labels\":{\"common.k8s.elastic.co/type\":\"elasticsearch\",\"elasticsearch.k8s.elastic.co/cluster-name\":\"cluster-name\"},\"name\":\"cluster-name-es-transport\",\"namespace\":\"default\",\"ownerReferences\":[{\"apiVersion\":\"elasticsearch.k8s.elastic.co/v1\",\"blockOwnerDeletion\":true,\"controller\":true,\"kind\":\"Elasticsearch\",\"name\":\"cluster-name\",\"uid\":\"a56dc6c0-6e9f-11ea-84c1-42010a800106\"}],\"resourceVersion\":\"79939085\",\"selfLink\":\"/api/v1/namespaces/default/services/cluster-name-es-transport\",\"uid\":\"4afcf347-95d4-11ea-bf80-42010a800051\"},\"spec\":{\"clusterIP\":\"10.72.5.221\",\"externalTrafficPolicy\":\"Cluster\",\"ports\":[{\"name\":\"tls-transport\",\"nodePort\":30085,\"port\":9300,\"protocol\":\"TCP\",\"targetPort\":9300}],\"publishNotReadyAddresses\":true,\"selector\":{\"common.k8s.elastic.co/type\":\"elasticsearch\",\"elasticsearch.k8s.elastic.co/cluster-name\":\"cluster-name\"},\"sessionAffinity\":\"None\",\"type\":\"LoadBalancer\"},\"status\":{\"loadBalancer\":{\"ingress\":[{\"ip\":\"192.168.1.1\"}]}}},\"requestMetadata\":{\"callerIp\":\"192.168.1.1\",\"callerSuppliedUserAgent\":\"elastic-operator/v0.0.0 (linux/amd64) kubernetes/$Format\"},\"resourceName\":\"core/v1/namespaces/default/services/cluster-name-es-transport\",\"response\":{\"@type\":\"core.k8s.io/v1.Service\",\"apiVersion\":\"v1\",\"kind\":\"Service\",\"metadata\":{\"creationTimestamp\":\"2020-05-14T11:16:01Z\",\"labels\":{\"common.k8s.elastic.co/type\":\"elasticsearch\",\"elasticsearch.k8s.elastic.co/cluster-name\":\"cluster-name\"},\"name\":\"cluster-name-es-transport\",\"namespace\":\"default\",\"ownerReferences\":[{\"apiVersion\":\"elasticsearch.k8s.elastic.co/v1\",\"blockOwnerDeletion\":true,\"controller\":true,\"kind\":\"Elasticsearch\",\"name\":\"cluster-name\",\"uid\":\"a56dc6c0-6e9f-11ea-84c1-42010a800106\"}],\"resourceVersion\":\"79939085\",\"selfLink\":\"/api/v1/namespaces/default/services/cluster-name-es-transport\",\"uid\":\"4afcf347-95d4-11ea-bf80-42010a800051\"},\"spec\":{\"clusterIP\":\"10.72.5.221\",\"externalTrafficPolicy\":\"Cluster\",\"ports\":[{\"name\":\"tls-transport\",\"nodePort\":30085,\"port\":9300,\"protocol\":\"TCP\",\"targetPort\":9300}],\"publishNotReadyAddresses\":true,\"selector\":{\"common.k8s.elastic.co/type\":\"elasticsearch\",\"elasticsearch.k8s.elastic.co/cluster-name\":\"cluster-name\"},\"sessionAffinity\":\"None\",\"type\":\"LoadBalancer\"},\"status\":{\"loadBalancer\":{\"ingress\":[{\"ip\":\"192.168.1.1\"}]}}},\"serviceName\":\"k8s.io\",\"status\":{}},\"receiveTimestamp\":\"2020-08-05T12:09:52.685937102Z\",\"resource\":{\"labels\":{\"cluster_name\":\"cluster-name\",\"location\":\"us-central1-a\",\"project_id\":\"gcp-project-name\"},\"type\":\"k8s_cluster\"},\"timestamp\":\"2020-08-05T12:09:24.989291Z\"}","outcome":"success"},"fileset":{"name":"audit"},"googlecloud":{"audit":{"authentication_info":{"principal_email":"system:serviceaccount:elastic-system:elastic-operator"},"authorization_info":[{"granted":true,"permission":"io.k8s.core.v1.services.update","resource":"core/v1/namespaces/default/services/cluster-name-es-transport","resource_attributes":null}],"method_name":"io.k8s.core.v1.services.update","request":{"proto_name":"core.k8s.io/v1.Service"},"request_metadata":{"caller_ip":"192.168.1.1","caller_supplied_user_agent":"elastic-operator/v0.0.0 (linux/amd64) kubernetes/$Format"},"resource_name":"core/v1/namespaces/default/services/cluster-name-es-transport","response":{"proto_name":"core.k8s.io/v1.Service","status":{"loadBalancer":{"ingress":[{"ip":"192.168.1.1"}]}}},"service_name":"k8s.io","status":{},"type":"type.googleapis.com/google.cloud.audit.AuditLog"}},"host":{"name":"filebeat-gcp-statefulset-0"},"input":{"type":"google-pubsub"},"labels":{"logging.googleapis.com/timestamp":"2020-08-05T12:09:24.989291Z"},"log":{"logger":"projects/gcp-project-name/logs/cloudaudit.googleapis.com%2Factivity"},"service":{"name":"k8s.io","type":"googlecloud"},"source":{"ip":"192.168.1.1"},"user":{"email":"system:serviceaccount:elastic-system:elastic-operator"},"user_agent":{"original":"elastic-operator/v0.0.0 (linux/amd64) kubernetes/$Format"}}, Private:(*pubsub.Message)(0xc000946c60), TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:common.MapStr(nil)}} (status=400): {"type":"mapper_parsing_exception","reason":"failed to parse field [googlecloud.audit.response.status] of type [keyword] in document with id 'd0bfda02f5-1404302606100912'. Preview of field's value: '{loadBalancer={ingress=[{ip=192.168.1.1}]}}'","caused_by":{"type":"illegal_state_exception","reason":"Can't get text on a START_OBJECT at 1:5343"}}
andrewkroh commented 4 years ago

With a quick look, it appears that the processor that's moving the value into the keyword googlecloud.audit.response.status field should be doing a type assertion. Like this it would only put string values into the field:

diff --git a/x-pack/filebeat/module/googlecloud/audit/config/pipeline.js b/x-pack/filebeat/module/googlecloud/audit/config/pipeline.js
index c467cc77c..8ab8750f1 100644
--- a/x-pack/filebeat/module/googlecloud/audit/config/pipeline.js
+++ b/x-pack/filebeat/module/googlecloud/audit/config/pipeline.js
@@ -85,7 +85,7 @@ function Audit(keep_original_message) {
             {from: "json.requestMetadata", to: "googlecloud.audit.request_metadata"},

             {from: "json.response.@type", to: "googlecloud.audit.response.proto_name"},
-            {from: "json.response.status", to: "googlecloud.audit.response.status"},
+            {from: "json.response.status", to: "googlecloud.audit.response.status", type: "string"},
             {from: "json.response.details.group", to: "googlecloud.audit.response.details.group"},
             {from: "json.response.details.kind", to: "googlecloud.audit.response.details.kind"},
             {from: "json.response.details.name", to: "googlecloud.audit.response.details.name"},
@@ -103,6 +103,7 @@ function Audit(keep_original_message) {
         ],
         mode: "rename",
         ignore_missing: true,
+        fail_on_error: false,
     });

I'll add some test cases and look for other similar issues.

andrewkroh commented 4 years ago

I have opened a PR to prevent the object from being copied into the keyword field. See #20465.