I'm trying to use Functionbeat 7.11.1 to get EKS Kubernetes API server logs from Cloud Watch to Elasticsearch.
Specifically, I was trying to convert the Kubernetes audit JSON events from a JSON string back into JSON using the decode_json_fields processor.
But for some reason it randomly fails on some audit events with this:
{
"type": "mapper_parsing_exception",
"reason": "failed to parse",
"caused_by": {
"type": "array_index_out_of_bounds_exception",
"reason": "Index -1 out of bounds for length 0"
}
}
My processor config looks like this:
processors:
- decode_json_fields:
when:
regexp:
log_stream: "^kube-apiserver-audit-.*"
fields: ["message"]
process_array: false
max_depth: 1
overwrite_keys: false
add_error_key: true
target: audit
Interestingly the event is dropped entirely when this error happens, instead of adding the error key as specified in the decode_json_fields doc.
add_error_key(Optional) If it set to true, in case of error while decoding json keys
errorfield is going to be part of event with error message. If it set to false, there will not be any error in event’s field. Even error occurs while decoding json keys. The default value is false.
I was expecting to find the same event in elasticsearch but with the message not decoded into audit field, and with the above error message in the error field. However, the event was missing entirely.
Most of the events do come through, but a handful doesn't decode properly even though the JSON is perfectly valid.
Here is the full error message grabbed from the CloudWatch logs with a few of the fields sanitised, but otherwise the same. I was able to decode the message field in the google chrome console without any errors at all.
What is going on?
2021-03-02T02:11:35.529Z WARN [elasticsearch] elasticsearch/client.go:408 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xfbc5200, ext:63750247891, loc:(*time.Location)(0x4758fc0)}, Meta:null, Fields:{"agent":{"ephemeral_id":"ff6efa78-dfbc-4dab-91f1-23ac8e416e01","hostname":"169.254.141.213","id":"cb8c8db8-9051-4797-afdc-e7a3bccdfc4e","name":"169.254.141.213","type":"functionbeat","version":"7.11.1"},"audit":{"annotations":{"authentication.k8s.io/legacy-token":"system:serviceaccount:olm:olm-operator-serviceaccount","authorization.k8s.io/decision":"allow","authorization.k8s.io/reason":"RBAC: allowed by ClusterRoleBinding \"olm-operator-binding-olm\" of ClusterRole \"system:controller:operator-lifecycle-manager\" to ServiceAccount \"olm-operator-serviceaccount/olm\""},"apiVersion":"audit.k8s.io/v1","auditID":"ffe9423d-a996-4a77-98c2-f9c9ab011e05","kind":"Event","level":"RequestResponse","objectRef":{"apiGroup":"authorization.k8s.io","apiVersion":"v1","resource":"subjectaccessreviews"},"requestObject":{"apiVersion":"authorization.k8s.io/v1","kind":"SubjectAccessReview","metadata":{"creationTimestamp":null},"spec":{"groups":["system:serviceaccounts","system:serviceaccounts:olm","system:authenticated"],"nonResourceAttributes":{"path":"/apis/packages.operators.coreos.com/v1","verb":"get"},"user":"system:serviceaccount:olm:olm-operator-serviceaccount"},"status":{"allowed":false}},"requestReceivedTimestamp":"2021-03-02T02:11:31.115750Z","requestURI":"/apis/authorization.k8s.io/v1/subjectaccessreviews","responseObject":{"apiVersion":"authorization.k8s.io/v1","kind":"SubjectAccessReview","metadata":{"creationTimestamp":null,"managedFields":[{"apiVersion":"authorization.k8s.io/v1","fieldsType":"FieldsV1","fieldsV1":{"f:spec":{"f:groups":{},"f:nonResourceAttributes":{".":{},"f:path":{},"f:verb":{}},"f:user":{}}},"manager":"package-server","operation":"Update","time":"2021-03-02T02:11:31Z"}]},"spec":{"groups":["system:serviceaccounts","system:serviceaccounts:olm","system:authenticated"],"nonResourceAttributes":{"path":"/apis/packages.operators.coreos.com/v1","verb":"get"},"user":"system:serviceaccount:olm:olm-operator-serviceaccount"},"status":{"allowed":true,"reason":"RBAC: allowed by ClusterRoleBinding \"olm-operator-binding-olm\" of ClusterRole \"system:controller:operator-lifecycle-manager\" to ServiceAccount \"olm-operator-serviceaccount/olm\""}},"responseStatus":{"code":201,"metadata":{}},"sourceIPs":["10.50.0.174"],"stage":"ResponseComplete","stageTimestamp":"2021-03-02T02:11:31.117874Z","user":{"groups":["system:serviceaccounts","system:serviceaccounts:olm","system:authenticated"],"uid":"77af9f2e-5ae4-4ba1-b48c-7ef2b1092125","username":"system:serviceaccount:olm:olm-operator-serviceaccount"},"userAgent":"package-server/v0.0.0 (linux/amd64) kubernetes/$Format","verb":"create"},"cloud":{"provider":"aws"},"ecs":{"version":"1.6.0"},"event":{"kind":"event"},"host":{"name":"169.254.141.213"},"id":"36007922570807878986754572832553098660594774277836701702","log_group":"/aws/eks/monitoring-infra-live-eks-cluster/cluster","log_stream":"kube-apiserver-audit-300e43ac9b25951edb96c09512cf4f38","message":"{\"kind\":\"Event\",\"apiVersion\":\"audit.k8s.io/v1\",\"level\":\"RequestResponse\",\"auditID\":\"ffe9423d-a996-4a77-98c2-f9c9ab011e05\",\"stage\":\"ResponseComplete\",\"requestURI\":\"/apis/authorization.k8s.io/v1/subjectaccessreviews\",\"verb\":\"create\",\"user\":{\"username\":\"system:serviceaccount:olm:olm-operator-serviceaccount\",\"uid\":\"77af9f2e-5ae4-4ba1-b48c-7ef2b1092125\",\"groups\":[\"system:serviceaccounts\",\"system:serviceaccounts:olm\",\"system:authenticated\"]},\"sourceIPs\":[\"10.50.0.174\"],\"userAgent\":\"package-server/v0.0.0 (linux/amd64) kubernetes/$Format\",\"objectRef\":{\"resource\":\"subjectaccessreviews\",\"apiGroup\":\"authorization.k8s.io\",\"apiVersion\":\"v1\"},\"responseStatus\":{\"metadata\":{},\"code\":201},\"requestObject\":{\"kind\":\"SubjectAccessReview\",\"apiVersion\":\"authorization.k8s.io/v1\",\"metadata\":{\"creationTimestamp\":null},\"spec\":{\"nonResourceAttributes\":{\"path\":\"/apis/packages.operators.coreos.com/v1\",\"verb\":\"get\"},\"user\":\"system:serviceaccount:olm:olm-operator-serviceaccount\",\"groups\":[\"system:serviceaccounts\",\"system:serviceaccounts:olm\",\"system:authenticated\"]},\"status\":{\"allowed\":false}},\"responseObject\":{\"kind\":\"SubjectAccessReview\",\"apiVersion\":\"authorization.k8s.io/v1\",\"metadata\":{\"creationTimestamp\":null,\"managedFields\":[{\"manager\":\"package-server\",\"operation\":\"Update\",\"apiVersion\":\"authorization.k8s.io/v1\",\"time\":\"2021-03-02T02:11:31Z\",\"fieldsType\":\"FieldsV1\",\"fieldsV1\":{\"f:spec\":{\"f:groups\":{},\"f:nonResourceAttributes\":{\".\":{},\"f:path\":{},\"f:verb\":{}},\"f:user\":{}}}}]},\"spec\":{\"nonResourceAttributes\":{\"path\":\"/apis/packages.operators.coreos.com/v1\",\"verb\":\"get\"},\"user\":\"system:serviceaccount:olm:olm-operator-serviceaccount\",\"groups\":[\"system:serviceaccounts\",\"system:serviceaccounts:olm\",\"system:authenticated\"]},\"status\":{\"allowed\":true,\"reason\":\"RBAC: allowed by ClusterRoleBinding \\\"olm-operator-binding-olm\\\" of ClusterRole \\\"system:controller:operator-lifecycle-manager\\\" to ServiceAccount \\\"olm-operator-serviceaccount/olm\\\"\"}},\"requestReceivedTimestamp\":\"2021-03-02T02:11:31.115750Z\",\"stageTimestamp\":\"2021-03-02T02:11:31.117874Z\",\"annotations\":{\"authentication.k8s.io/legacy-token\":\"system:serviceaccount:olm:olm-operator-serviceaccount\",\"authorization.k8s.io/decision\":\"allow\",\"authorization.k8s.io/reason\":\"RBAC: allowed by ClusterRoleBinding \\\"olm-operator-binding-olm\\\" of ClusterRole \\\"system:controller:operator-lifecycle-manager\\\" to ServiceAccount \\\"olm-operator-serviceaccount/olm\\\"\"}}","message_type":"DATA_MESSAGE","owner":"1234567890","subscription_filters":["fnb-cloudwatch-stack-fnbcloudwatchSFawseksmonitoringinfraliveeksclustercluster-XXXXXXXXXXX"]}, Private:interface {}(nil), TimeSeries:false}, Flags:0x1, Cache:publisher.EventCache{m:common.MapStr(nil)}} (status=400): {
"type": "mapper_parsing_exception",
"reason": "failed to parse",
"caused_by": {
"type": "array_index_out_of_bounds_exception",
"reason": "Index -1 out of bounds for length 0"
}
}