Fluent-bit: spurious field mapping errors in ES output

Created on 25 Feb 2019 · 19Comments · Source: fluent/fluent-bit

Bug Report

Describe the bug

I see the error messages shown below in the log of my fluent-bit pods.
according to kubectl get pods -l app --all-namespaces --show-labels we only use values for the applabel that match /[:alpha:][-:alphanum:]*[:alpha]/

I have no idea where the app object is coming from.

[2019/02/25 09:31:35] [ warn] [out_es] Elasticsearch error
{"took":2,"errors":true,"items":[{"index":{"_index":"kubernetes-2019.02.25","_type":"flb_type","_id":"nt_-I2kBNo3QnVfwzT9R","status":400,"error":{"type":"mapper_parsing_exception","reason":"object mapping for [kubernetes.labels.app] tried to parse field [app] as object, but found a concrete value"}}},{"index":{"_index":"kubernetes-2019.02.25","_type":"flb_type","_id":"n9_-I2kBNo3QnVfwzT9R","status":400,"error":{"type":"mapper_parsing_exception","reason":"object mapping for [kubernetes.labels.app] tried to parse field [app] as object, but found a concrete value"}}},{"index":{"_index":"kubernetes-2019.02.25","_type":"flb_type","_id":"oN_-I2kBNo3QnVfwzT9R","status":400,"error":{"type":"mapper_parsing_exception","reason":"object mapping for [kubernetes.labels.app] tried to parse field [app] as object, but found a concrete value"}}},{"index":{"_index":"kubernetes-2019.02.25","_type":"flb_type","_id":"od_-I2kBNo3QnVfwzT9R","status":400,"error":{"

Expected behavior
all fields of the app label to be unstructured strings.

Your Environment

Version used: fluent-bit 1.0.4 via helm 1.7.0, ES 6.6.0 via helm chart 1.21.0
Configuration:

my config map is:

apiVersion: v1
kind: ConfigMap
metadata:
  name: logging-fluent-bit-config
  labels:
    app: fluent-bit
    chart: fluent-bit-1.8.0
    heritage: Tiller
    release: logging
data:
  fluent-bit-service.conf: |-
    [SERVICE]
        Flush        1
        Daemon       Off
        Log_Level    info
        Parsers_File parsers.conf
        Parsers_File parsers_custom.conf
        HTTP_Server  On
        HTTP_Listen  0.0.0.0
        HTTP_Port    2020

  fluent-bit-input.conf: |-
    [INPUT]
        Name             tail
        Path             /var/log/containers/*.log
        Parser           docker
        Tag              kube.*
        Refresh_Interval 5
        Mem_Buf_Limit    5MB
        Skip_Long_Lines  On
        DB               /tail-db/tail-containers-state.db
        DB.Sync          Normal
    [INPUT]
        Name            systemd
        Tag             systemd.*
        Systemd_Filter  _SYSTEMD_UNIT="docker.service"
        Systemd_Filter  _SYSTEMD_UNIT="kubelet.service"
        Systemd_Filter  _SYSTEMD_UNIT="etcd-member.service"
        Systemd_Filter  _SYSTEMD_UNIT="etcd-backup.service"
        Systemd_Filter  _SYSTEMD_UNIT="consul.service"
        Systemd_Filter  _SYSTEMD_UNIT="consul-backup.service"
        Systemd_Filter  _SYSTEMD_UNIT="vault.service"
        Max_Entries     1000
        Read_From_Tail  true
    [INPUT]
        Name            syslog
        Mode            udp
        Port            5140
        Tag             neuvector.*
        Parser          syslog-neuvector
        Chunk_Size      32
        Buffer_Size     64
    [INPUT]
        Name            systemd
        Tag             audit.system.*
        Systemd_Filter  _TRANSPORT=audit
        DB               /tail-db/tail-audit-system-state.db
        DB.Sync          Normal
    [INPUT]
        Name            systemd
        Tag             audit.vault.*
        Systemd_Filter  SYSLOG_IDENTIFIER=vault-audit
        DB               /tail-db/tail-audit-vault-state.db
        DB.Sync          Normal
    [INPUT]
        Name             tail
        Path             /var/log/audit/apiserver/apiserver.log
        Tag              audit.apiserver.*
        Parser           parse-audit-apiserver
        Refresh_Interval 5
        Mem_Buf_Limit    5MB
        Skip_Long_Lines  On
        DB               /tail-db/tail-audit-apiserver-state.db
        DB.Sync          Normal

  fluent-bit-filter.conf: |-
    [FILTER]
        Name                kubernetes
        Match               kube.*
        Kube_URL            https://kubernetes.default.svc:443
        Kube_CA_File        /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
        Kube_Token_File     /var/run/secrets/kubernetes.io/serviceaccount/token
        Merge_Log           On
    # suppres structured app labels
    [FILTER]
        Name             record_modifier
        Match            kube.*

    # this section is wrongly indented by helm chart

  fluent-bit-output.conf: |-

    [OUTPUT]
        Name  es-kubernetes
        Match kube.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix kubernetes
    [OUTPUT]
        Name  es-systemd
        Match systemd.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix systemd
    [OUTPUT]
        Name  es-autit-system
        Match audit.system.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix audit-system
    [OUTPUT]
        Name  es-audit-vault
        Match audit.vault.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix audit-vault
    [OUTPUT]
        Name  es-audit-apiserver
        Match audit.apiserver.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix audit-apiserver
    [OUTPUT]
        Name  es-neuvector
        Match neuvector.*
        Host  logging-elasticsearch-client
        Port  9200
        Logstash_Format On
        Retry_Limit False
        Type  flb_type
        Logstash_Prefix neuvector


  fluent-bit.conf: |-
    @INCLUDE fluent-bit-service.conf
    @INCLUDE fluent-bit-input.conf
    @INCLUDE fluent-bit-filter.conf
    @INCLUDE fluent-bit-output.conf

  parsers.conf: |-
    [PARSER]
        Name        syslog-neuvector
        Format      regex
        Regex       /^\<(?<priority>[0-9]+)\>(?<time>[^ Z]*)Z (?<host>[^ ]*) (?<ident>[a-zA-Z0-9_\/\.\-]*)(?:\[(?<pid>[0-9]+)\])?\:? *(?<full_message>(?:(?:notification=(?<notification>[^,]*))|(?:name=(?<name>[^,]*))|(?:level=(?<level>[^,]*))|(?:reported_timestamp=(?<reported_timestamp>[^,]*))|(?:reported_at=(?<reported_at>[^,]*))|(?:cluster_name=(?<cluster_name>[^,]*))|(?:host_id=(?<host_id>[^,]*))|(?:host_name=(?<host_name>[^,]*))|(?:controller_id=(?<controller_id>[^,]*))|(?:controller_name=(?<controller_name>[^,]*))|(?:enforcer_id=(?<enforcer_id>[^,]*))|(?:enforcer_name=(?<enforcer_name>[^,]*))|(?:workload_id=(?<workload_id>[^,]*))|(?:workload_name=(?<workload_name>[^,]*))|(?:workload_domain=(?<workload_domain>[^,]*))|(?:workload_image=(?<workload_image>[^,]*))|(?:category=(?<category>[^,]*))|(?:user=(?<user>[^,]*))|(?:user_roles=(?<user_roles>[^,]*))|(?:user_addr=(?<user_addr>[^,]*))|(?:user_session=(?<user_session>[^,]*))|(?:message=(?<message>[^,]*))|[^,=]+=[^,=]*|,+)*)$/
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S

    [PARSER]
        Name        parse-audit-apiserver
        Format      json
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S %z
        Decode_Field json log

Source

cypherfox

Most helpful comment

@mtparet I rewrote it into this

function dedot(tag, timestamp, record)
    if record["kubernetes"] == nil then
        return 0, 0, 0
    end
    dedot_keys(record["kubernetes"]["annotations"])
    dedot_keys(record["kubernetes"]["labels"])
    return 1, timestamp, record
end

function dedot_keys(map)
    if map == nil then
        return
    end
    local new_map = {}
    local changed_keys = {}
    for k, v in pairs(map) do
        local deslashed = string.gsub(k, "%/", "_")
        local dedotted = string.gsub(deslashed, "%.", "_")
        if dedotted ~= k then
            new_map[dedotted] = v
            changed_keys[k] = true
        end
    end
    for k in pairs(changed_keys) do
        map[k] = nil
    end
    for k, v in pairs(new_map) do
        map[k] = v
    end
end

gmlexx on 29 Feb 2020

👍7 ❤2

All 19 comments

Additionally: there are no log message from the fluent-bit pods themselves. Is this intentional? All other pods seem to work.

cypherfox on 25 Feb 2019

You can find an explanation here.
Beats solved it by replacing dots in labels with _.

pichouk on 21 Mar 2019

We solved this by adding a Lua filter after the Kubernetes filter:

[FILTER]
    Name    lua
    Match   kube.*
    script  /fluent-bit/etc/functions.lua
    call    dedot

function dedot(tag, timestamp, record)
    if record["kubernetes"] == nil then
        return 0, 0, 0
    end
    dedot_keys(record["kubernetes"]["annotations"])
    dedot_keys(record["kubernetes"]["labels"])
    return 1, timestamp, record
end

function dedot_keys(map)
    if map == nil then
        return
    end
    for k, v in pairs(map) do
        dedotted = string.gsub(k, "%.", "_")
        if k ~= dedotted then
            map[dedotted] = v
            map[k] = nil
        end
    end
end

It would be cool to have this support natively though.

andreykaipov on 3 May 2019

👍3

@andreykaipov Thanks for providing your script! When I use it, paris(map) fails becausemapis nil indedot_keys. Did you apply this filter before or after thekubernetes` filter? (I did after)

simonwh on 9 May 2019

Hi @simonwh - we actually ran into it that yesterday too. It was working okay until a pod with no annotations or labels started running, which is rare enough I didn't think it was possible!

I've edited my original post to add a nil check to dedot_keys to return early if the map is nil so that Fluent Bit doesn't crash on those kinds of records. That got it working for us again.

andreykaipov on 9 May 2019

@andreykaipov how can I reproduce the crash ?

edsiper on 9 May 2019

Hi @edsiper, the crash I was referring to isn't anything wrong with Fluent Bit. It was just my original Lua script not accounting for pods with an empty annotations or labels map.

PANIC: unprotected error in call to Lua API (/fluent-bit/etc/functions.lua:19: bad argument #1 to 'pairs' (table expected, got nil))

andreykaipov on 9 May 2019

Hi @andreykaipov I believe that your dedot function works fine, but for some reason my json annotations just partially transformed

{
    "kubernetes": {
        "annotations": {
            "cluster-autoscaler_kubernetes_io_safe-to-evict": "true",
            "kubernetes.io/limit-ranger": "LimitRanger plugin set: cpu request for init container assets"
        },
        "container_name": "saml",
        "docker_id": "1aefe0b3ef8306dfaa411a7c5188c51679be651d68b313fa3635c0a63ce701eb",
        "host": "ip-172-16-40-62.ec2.internal",
        "labels": {
            "app": "login",
            "pod-template-hash": "74c68f9d5",
            "release": "test-login"
        },
        "namespace_name": "default",
        "pod_id": "eb746a32-ecd0-11e9-8d9a-0ed429943b82",
        "pod_name": "test-login-74c68f9d5-lmfnq"
    },
    "log": "172.16.84.128 - - [24/Oct/2019 12:54:47] \"GET /test/ HTTP/1.1\" 401 -\n",
    "stream": "stderr",
    "time": "2019-10-24T12:54:47.10424059Z"
}

I've tested function locally and it works properly. In fluent-bit configuration there are only 2 filters:

[FILTER]
    Name                kubernetes
    Match               kube.*
    Kube_Tag_Prefix     kube.var.log.containers.
    Kube_URL            https://kubernetes.default.svc:443
    Kube_CA_File        /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
    Kube_Token_File     /var/run/secrets/kubernetes.io/serviceaccount/token
    Merge_Log           On
    K8S-Logging.Parser  On
    K8S-Logging.Exclude On

[FILTER]
    Name    lua
    Match   kube.*
    script  /fluent-bit/etc/functions.lua
    call    dedot

Do you have any clue, why that may happen?

gmlexx on 24 Oct 2019

It seems that changing map during iteration is a bad idea

gmlexx on 25 Oct 2019

Run into the same issue, the lua function does not seems to be working, i'm investigating.

mtparet on 28 Feb 2020

@mtparet I rewrote it into this

function dedot(tag, timestamp, record)
    if record["kubernetes"] == nil then
        return 0, 0, 0
    end
    dedot_keys(record["kubernetes"]["annotations"])
    dedot_keys(record["kubernetes"]["labels"])
    return 1, timestamp, record
end

function dedot_keys(map)
    if map == nil then
        return
    end
    local new_map = {}
    local changed_keys = {}
    for k, v in pairs(map) do
        local deslashed = string.gsub(k, "%/", "_")
        local dedotted = string.gsub(deslashed, "%.", "_")
        if dedotted ~= k then
            new_map[dedotted] = v
            changed_keys[k] = true
        end
    end
    for k in pairs(changed_keys) do
        map[k] = nil
    end
    for k, v in pairs(new_map) do
        map[k] = v
    end
end

gmlexx on 29 Feb 2020

👍7 ❤2

:+1: please include a native dedot option in fluent-bit (and not only in ES plugin)

BarthV on 17 Apr 2020

👍3 😕1

+1 just encountered the same issue. Whole logging is broken now.
That has started when I've tried to enable "recommended" kubernetes labels. 1 2
Extremely appreciate guys who have developed and shared their scripts!!! Thanks!!!

den-is on 30 Apr 2020

@mtparet I rewrote it into this

function dedot(tag, timestamp, record)
    if record["kubernetes"] == nil then
        return 0, 0, 0
    end
    dedot_keys(record["kubernetes"]["annotations"])
    dedot_keys(record["kubernetes"]["labels"])
    return 1, timestamp, record
end

function dedot_keys(map)
    if map == nil then
        return
    end
    local new_map = {}
    local changed_keys = {}
    for k, v in pairs(map) do
        local deslashed = string.gsub(k, "%/", "_")
        local dedotted = string.gsub(deslashed, "%.", "_")
        if dedotted ~= k then
            new_map[dedotted] = v
            changed_keys[k] = true
        end
    end
    for k in pairs(changed_keys) do
        map[k] = nil
    end
    for k, v in pairs(new_map) do
        map[k] = v
    end
end

@gmlexx Thanks a lot! worked here.

@edsiper this lua script that @gmlexx / @andreykaipov made is very useful, could we create a kind of template and add in the code examples? https://github.com/fluent/fluent-bit/tree/master/scripts

nullck on 9 May 2020

for now, we can add that script into our scripts directory, anyone wants to submit the PR?

edsiper on 19 May 2020

is there a workaround for this?

The filter cannot be used as described above as Fluent-bit is installed via Helm. Containers look for scripts inside, of course there is no script.

[FILTER]
    Name    lua
    Match   kube.*
    script  /fluent-bit/etc/functions.lua
    call    dedot

I will be very appreciated if you can advise how to make it run on Kubernetes environment.

tirelibirefe on 19 Jul 2020

@tirelibirefe

The filter cannot be used as described above ...

k8s questions are a bit out of scope here. And it seems that you just don't know how to do it ;)

You can simply mount a configMap with lua script and fluent-bit config. and load it in rawConfig chart value.

There's few details from my own config here :
https://gist.github.com/BarthV/17521ff8cc5c5b3b704c9e2f491c7e60

BarthV on 19 Jul 2020

👍1

But, we're still waiting to see dedot option to be included upstream :'(

BarthV on 19 Jul 2020

👍3

k8s questions are a bit out of scope here. And it seems that you just don't know how to do it ;)

@BarthV I cannot say you're wrong ;) You helped me, I'm very appreciated. Thank you!

tirelibirefe on 19 Jul 2020

Was this page helpful?

0 / 5 - 0 ratings

Related issues

compilerd binary or packages

mhf-ir · 4Comments

Loki plugin - remove labels from Loki fields

jcdauchy-moodys · 3Comments

Old pegged versions removed for CentOS

brycefisher · 3Comments

nginx regex does not generate the fields

mbelchin · 3Comments

Mac OS - Unable to build fluent-bit due to math.h library

iamshreeram · 3Comments