Filebeat logfile property expansion json

Elastic Stack Beats
1

Did replace fluentd/logstash with filebeat. Use filebeat on 6.2 version and works well, filebeat-prospector with following config. Explaining: type docker did not work, because json in json problem, error messages with parsing that. With type log works good, got result in elasticsearch.

data:
  kubernetes.yml: |-
    # - type: docker
    #   containers.ids:
    #   - "*"
    #   json.message_key: log
    #   json.keys_under_root: false  
    #   processors:
    #     - add_kubernetes_metadata:
    #         in_cluster: true
    #         _type: ${ENV}
    - type: log
      paths:
        - /var/lib/docker/containers/*/*.log
      tags: ['${ENV}']
      json.message_key: log
      json.keys_under_root: true
      processors:
        - add_kubernetes_metadata:
            in_cluster: true

Problem interpreting LOG property on .. see elasticsearch JSON, log property isn't expanded as expected.. Previous logstash implementations works in a manner to expand that to accessing req_id:

{
  "_index": "filebeat-6.2.2-2018.02.22",
  "_type": "doc",
  "_id": "YY1CvmEB2trujBDGJh6G",
  "_version": 1,
  "_score": null,
  "_source": {
    "@timestamp": "2018-02-22T16:03:13.830Z",
    "source": "/var/lib/docker/containers/f5d45b3a82edc03b4eae73e30a6d2b5c947e040ec3e8fcb1ed3520b36b6df172/f5d45b3a82edc03b4eae73e30a6d2b5c947e040ec3e8fcb1ed3520b36b6df172-json.log",
    "log": "{\"name\":\"api\",\"hostname\":\"api-746cc7c4f4-fr94g\",\"pid\":91,\"req_id\":\"deac7d70-8975-4bb3-a4a8-c19d2b7d8859\",\"handler\":\"concurrencyDecreaseMiddleware\",\"level\":20,\"msg\":\"end\",\"time\":\"2018-02-22T16:03:08.894Z\",\"v\":0}",
    "prospector": {
      "type": "log"
    },
    "kubernetes": {
      "labels": {
        "pod-template-hash": "3027737090",
        "name": "api"
      },
      "container": {
        "name": "api"
      },
      "pod": {
        "name": "api-746cc7c4f4-fr94g"
      },
      "node": {
        "name": "172.31.25.241"
      },
      "namespace": "dev"
    },
    "beat": {
      "name": "filebeat-2lfqb",
      "hostname": "filebeat-2lfqb",
      "version": "6.2.2"
    },
    "stream": "stdout",
    "time": "2018-02-22T16:03:08.895228712Z",
    "offset": 335910,
    "tags": [
      "aws"
    ],
    "meta": {
      "cloud": {
        "provider": "ec2",
        "region": "eu-central-1",
        "availability_zone": "eu-central-1b",
        "instance_id": "....",
        "machine_type": "m4.xlarge"
      }
    }
  },
  "fields": {
    "@timestamp": [
      "2018-02-22T16:03:13.830Z"
    ]
  },
  "highlight": {
    "kubernetes.container.name": [
      "@kibana-highlighted-field@api@/kibana-highlighted-field@"
    ],
    "kubernetes.namespace": [
      "@kibana-highlighted-field@dev@/kibana-highlighted-field@"
    ]
  },
  "sort": [
    1519315393830
  ]
}

What did the trick?

2

What was the actual error with the docker type? Generally speaking, that approach should have worked as well. If you can share the logs, that would be helpful.

3

Using docker as type with configuration

  kubernetes.yml: |-
    - type: docker
      containers.ids:
      - "*"
      json.message_key: log
      json.keys_under_root: false
      tags: ['${ENV}']
      processors:
        - add_kubernetes_metadata:
            in_cluster: true

Error log in using type docker

 |2018-03-02T09:12:52.675Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|---|---|---|---|
|2018-03-02T09:12:52.675Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.675Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: json: cannot unmarshal number into Go value of type map[string]interface {}|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'p' looking for beginning of value|
|2018-03-02T09:12:52.676Z|ERROR|reader/json.go:32|Error decoding JSON: json: cannot unmarshal number into Go value of type map[string]interface {}|
|2018-03-02T09:12:52.677Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '<' looking for beginning of value|
|2018-03-02T09:12:52.773Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: json: cannot unmarshal number into Go value of type map[string]interface {}|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'e' looking for beginning of value|
|2018-03-02T09:12:52.774Z|ERROR|reader/json.go:32|Error decoding JSON: EOF|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '<' looking for beginning of value|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.775Z|ERROR|reader/json.go:32|Error decoding JSON: json: cannot unmarshal number into Go value of type map[string]interface {}|
|2018-03-02T09:12:52.776Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.776Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'p' looking for beginning of value|
|2018-03-02T09:12:52.776Z|ERROR|reader/json.go:32|Error decoding JSON: EOF|
|2018-03-02T09:12:52.776Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '<' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: json: cannot unmarshal number into Go value of type map[string]interface {}|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'i' in literal true (expecting 'r')|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '>' looking for beginning of value|
|2018-03-02T09:12:52.777Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '@' looking for beginning of value|
|2018-03-02T09:12:52.872Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
4

@tudor - any idea to solve my issue? Could a elasticsearch preprocessing solve that?

5

Sorry for the delay. If you are deploying this on Kubernetes, I recommend checking out our sample manifest files: https://www.elastic.co/guide/en/beats/filebeat/6.2/running-on-kubernetes.html

6

Yes, I deployed that in this way and checked that..

$ kubectl -n logging get ds
NAME         DESIRED   CURRENT   READY     UP-TO-DATE   AVAILABLE   NODE SELECTOR   AGE
filebeat     15        15        15        15           15          <none>          14d

Configmaps would be created

$ kubectl -n logging get cm
NAME                   DATA      AGE
filebeat-config        1         14d
filebeat-prospectors   1         14d

In filebeat prospectors tested with docker and log.. Docker did not work correctly, json error as described. Log did not do the json expansion..

$ kubectl -n logging describe cm filebeat-prospectors
Name:         filebeat-prospectors
Namespace:    logging
Labels:       k8s-app=filebeat
              kubernetes.io/cluster-service=true
Data
====
kubernetes.yml:
----
#- type: docker
#  containers.ids:
#  - "*"
#  json.message_key: log
#  json.keys_under_root: false
#  tags: ['${ENV}']
#  processors:
#    - add_kubernetes_metadata:
#        in_cluster: true
- type: log
  paths:
    - /var/lib/docker/containers/*/*.log
  tags: ['${ENV}']
  json.message_key: log
  json.keys_under_root: false
  processors:
    - add_kubernetes_metadata:
        in_cluster: true
Events:  <none>

That result in Kibana

{
  "_index": "filebeat-6.2.2-2018.03.09",
  "_type": "doc",
  "_id": "3FgkC2IBkKodztBHbedw",
  "_version": 1,
  "_score": null,
  "_source": {
    "@timestamp": "2018-03-09T14:22:38.470Z",
    "kubernetes": {
      "namespace": "unapologetic-urubu",
      "labels": {
        "name": "api",
        "pod-template-hash": "4147533276"
      },
      "container": {
        "name": "api"
      },
      "pod": {
        "name": "api-4147533276-kbdxv"
      },
      "node": {
        "name": "172.31.111.24"
      }
    },
    "beat": {
      "hostname": "filebeat-9j7xk",
      "version": "6.2.2",
      "name": "filebeat-9j7xk"
    },
    "meta": {
      "cloud": {
        "availability_zone": "xxx",
        "provider": "xxx",
        "instance_id": "i-xxx",
        "machine_type": "m...",
        "region": "xxx"
      }
    },
    "source": "/var/lib/docker/containers/xxx/xxx..9c6fc51-json.log",
    "offset": 95959900,
    "json": {
      "log": "{\"name\":\"api\",\"hostname\":\"api-4147533276-kbdxv\",\"pid\":102,\"level\":40,\"msg\":\"TTL headers missing, fallback to 60s.\",\"time\":\"2018-03-09T14:22:36.780Z\",\"v\":0}",
      "stream": "stdout",
      "time": "2018-03-09T14:22:36.781187871Z"
    },
    "tags": [
      "aws"
    ],
    "prospector": {
      "type": "log"
    }
  },
  "fields": {
    "@timestamp": [
      "2018-03-09T14:22:38.470Z"
    ]
  },
  "highlight": {
    "kubernetes.container.name": [
      "@kibana-highlighted-field@api@/kibana-highlighted-field@"
    ],
    "kubernetes.labels.name": [
      "@kibana-highlighted-field@api@/kibana-highlighted-field@"
    ]
  },
  "sort": [
    1520605358470
  ]
}
7

There are 2 problems here:

  • I'm guessing not all your containers are outputting JSON, hence the decoding errors you see in the logs
  • Docker prospector does the first decoding for you, so you don't need to specify message_key: log, JSON settings affect the inner message, and not the json-file format.

Can you try to remove the json.message_key: log part?

If that doesn't work I would try to isolate a single container outside kubernetes for easier testing, pasting a few lines of your container output here could also help to understand the errors.

Best regards

8

So, changed that to

data:
  kubernetes.yml: |-
    - type: docker
      containers.ids:
        - '*'
      paths:
        - /var/lib/docker/containers/*/*.log
      tags: ['${ENV}']
      json.keys_under_root: true
      json.add_error_key: false
      processors:
        - add_kubernetes_metadata:
            in_cluster: true

and got lot of errros

|2018-03-15T12:25:37.726Z|WARN|elasticsearch/client.go:502|Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x34914975, ext:63655856109, loc:(*time.Location)(nil)}, Meta:common.MapStr(nil), Fields:common.MapStr{"pid":1, "stream":"stdout", "level":30, "name":"train-online", "tags":[]string{"aws"}, "kubernetes":common.MapStr{"node":common.MapStr{"name":"172.31.25.6"}, "namespace":"valiant-viper", "labels":common.MapStr{"controller-uid":"9bf7dd8b-207f-11e8-a9cd-06fa2d724cac", "job-name":"expense-classifier-training-1520259300", "name":"expense-classifier"}, "container":common.MapStr{"name":"expense-classifier"}, "pod":common.MapStr{"name":"expense-classifier-training-1520259300-wblgb"}}, "offset":1448, "hostname":"expense-classifier-training-1520259300-wblgb", "system":"ama-muc", "prospector":common.MapStr{"type":"docker"}, "msg":"training-start", "source":"/var/lib/docker/containers/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35-json.log", "v":0, "time":"2018-03-05T14:15:09.881Z", "beat":common.MapStr{"name":"filebeat-nf6cw", "hostname":"filebeat-nf6cw", "version":"6.2.2"}, "meta":common.MapStr{"cloud":common.MapStr{"instance_id":"i-0e27847a344855e55", "machine_type":"m4.2xlarge", "region":"eu-central-1", "availability_zone":"eu-central-1b", "provider":"ec2"}}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc420391ba0), Source:"/var/lib/docker/containers/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35-json.log", Offset:1448, Timestamp:time.Time{wall:0xbea2b7564929a163, ext:16600182653, loc:(*time.Location)(0x200bc40)}, TTL:-1, Type:"docker", FileStateOS:file.StateOS{Inode:0x202cb3, Device:0xca09}}}, Flags:0x1} (status=400): {"type":"mapper_parsing_exception","reason":"object mapping for [system] tried to parse field [system] as object, but found a concrete value"}|
|---|---|---|---|
|2018-03-15T12:25:37.726Z|WARN|elasticsearch/client.go:502|Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0x337c7c77, ext:63655856123, loc:(*time.Location)(nil)}, Meta:common.MapStr(nil), Fields:common.MapStr{"source":"/var/lib/docker/containers/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35-json.log", "msg":"training-done", "system":"ama-muc", "tags":[]string{"aws"}, "level":30, "offset":1781, "kubernetes":common.MapStr{"container":common.MapStr{"name":"expense-classifier"}, "pod":common.MapStr{"name":"expense-classifier-training-1520259300-wblgb"}, "node":common.MapStr{"name":"172.31.25.6"}, "namespace":"valiant-viper", "labels":common.MapStr{"controller-uid":"9bf7dd8b-207f-11e8-a9cd-06fa2d724cac", "job-name":"expense-classifier-training-1520259300", "name":"expense-classifier"}}, "beat":common.MapStr{"name":"filebeat-nf6cw", "hostname":"filebeat-nf6cw", "version":"6.2.2"}, "time":"2018-03-05T14:15:23.863Z", "name":"train-online", "meta":common.MapStr{"cloud":common.MapStr{"instance_id":"i-", "machine_type":"m4.2xlarge", "region":"eu-central-1", "availability_zone":"eu-..-1b", "provider":"ec2"}}, "stream":"stdout", "hostname":"expense-classifier-training-1520259300-wblgb", "pid":1, "v":0, "prospector":common.MapStr{"type":"docker"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc420391ba0), Source:"/var/lib/docker/containers/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35/13cfcd3e09d88457cbe5adea8c37673d52231622f1377f4e74ea2106f5b51b35-json.log", Offset:1781, Timestamp:time.Time{wall:0xbea2b7564929a163, ext:16600182653, loc:(*time.Location)(0x200bc40)}, TTL:-1, Type:"docker", FileStateOS:file.StateOS{Inode:0x202cb3, Device:0xca09}}}, Flags:0x1} (status=400): {"type":"mapper_parsing_exception","reason":"object mapping for [system] tried to parse field [system] as object, but found a concrete value"}|
|2018-03-15T12:25:37.727Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'i' in literal true (expecting 'r')|
|2018-03-15T12:25:37.727Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'i' in literal true (expecting 'r')|
|2018-03-15T12:25:37.727Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character 'u' looking for beginning of value|
|2018-03-15T12:25:37.727Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-15T12:25:37.727Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
|2018-03-15T12:25:37.728Z|ERROR|reader/json.go:32|Error decoding JSON: invalid character '\x1b' looking for beginning of value|
9

I can see from the error that there is a mapping error, your JSON contains a value for system key, but that namespace is reserved by Filebeat system module, perhaps you can avoid adding keys under root?

10

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.