主页 / server / 问题 / 1146109
Accepted
HJ S
Asked: 2023-10-18 23:52:12 +0800 CST

Kubernetes中的Fluent-bit无法正确输入时间戳数据

  • 772

在我的公司，我使用 Terraform 构建了一个 K8s 集群，并使用 EFK（Elasticsearch、Fluent-bit、Kibana）配置了日志系统。

k8s 和 Elasticsearch 使用 AWS 的 EKS 和 Opensearch Servcie (ES 7.10)，Fluent-bit 通过 Helm 作为 Daemonset 单独安装。

https://artifacthub.io/packages/helm/ Fluent/fluence-bit

在 Fluent-bit Config 的情况下，其结构如下。

config:
   inputs: |
     [INPUT]
         Name tail
         Exclude_Path /var/log/containers/cloudwatch-agent*, /var/log/containers/fluent-bit*, /var/log/containers/aws-node*, /var/log/containers/kube-proxy*, / var/log/containers/aws-load-balancer*, /var/log/containers/cert-manager*, /var/log/containers/coredns*, /var/log/containers/ebs-csi*, /var/ log/containers/grafana*, /var/log/containers/karpenter*, /var/log/containers/metrics-server*, /var/log/containers/prometheus*
         Path /var/log/containers/*.log
         Tag kube.*
         Mem_Buf_Limit 50MB
         multiline.parser python-custom

   outputs: |
     [OUTPUT]
         Name es
         Match kube.*
         Host ${es_domain_name}
         Port 443
         TLS On
         AWS_Auth On
         AWS_Region ${region}
         Retry_Limit 6
         Replace_Dots On
         Trace_Error On

   filters: |
     [FILTER]
         Name kubernetes
         Match kube.*
         Merge_Log On
         Merge_Log_Key log_processed
         Keep_LogOff
         K8S-Logging.Parser On
         K8S-Logging.Exclude On

   customParsers: |
     [MULTILINE_PARSER]
         name python-custom
         type regex
         flush_timeout 1000
         rule "start_state" "/stderr F(.*)/" "cont"
         rule "cont" "/stderr F(.*)/" "cont"

总的来说，它工作得很好，但是有一天，在某种情况之后，我注意到 Fluent-bit 收集的所有日志都指向相同的时间戳。

之前Pod输出的日志是用准确的时间戳记录的，但是Pod重新加载后，日志继续用固定的@timestamp记录，并且由于日志是在过去的时区累积的，所以出现以下现象：在 kibana 中查看。

日志都是实时传输到ES的，但是由于它们都是在过去固定的时间收集的，因此无法执行正确的查询。

在此输入图像描述

// Unlike the timestamp output in the actual application, the timestamp recorded in Fluent-bit remains the same.
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:48:55...[2023-10-16 09:48:55]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:48:55...[2023-10-16 09:48:55]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:53:55...[2023-10-16 09:53:55]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:58:03...[2023-10-16 09:58:03]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:58:03...[2023-10-16 09:58:03]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:58:03...[2023-10-16 09:58:03]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:58:55...[2023-10-16 09:58:55]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T09:58:55...[2023-10-16 09:58:55]... 
Oct 16, 2023 @ 16:13:36.142 2023-10-16T10:03:03...[2023-10-16 10:03:03]...
Oct 16, 2023 @ 16:13:36.142 2023-10-16T10:03:55...[2023-10-16 10:03:55]...

更新和重新加载为每个服务运行的 Pod 时会出现此问题。我确认新创建的Pod的inotify_fs_add日志输出到Fluent-bit，无法确认其他错误日志。

吊舱重新装载

│ backend-api-deployment-5d9fc55496-8mppx                            ●  1/1          0 Running
│ backend-api-deployment-57d68dd4f5-djn8x                            ●  1/1          0 Terminating

流利位日志

│ Fluent Bit v2.1.8
│ * Copyright (C) 2015-2022 The Fluent Bit Authors
│ * Fluent Bit is a CNCF sub-project under the umbrella of Fluentd
│ * https://fluentbit.io
│
│ [2023/10/16 16:05:00] [ info] [fluent bit] version=2.1.8, commit=1d83649441, pid=1
│ [2023/10/16 16:05:00] [ info] [storage] ver=1.4.0, type=memory, sync=normal, checksum=off, max_chunks_up=128
│ [2023/10/16 16:05:00] [ info] [cmetrics] version=0.6.3
│ [2023/10/16 16:05:00] [ info] [ctraces ] version=0.3.1
│ [2023/10/16 16:05:00] [ info] [input:tail:tail.0] initializing
│ [2023/10/16 16:05:00] [ info] [input:tail:tail.0] storage_strategy='memory' (memory only)
│ [2023/10/16 16:05:00] [ info] [input:tail:tail.0] multiline core started
│ [2023/10/16 16:05:00] [ info] [filter:kubernetes:kubernetes.0] https=1 host=kubernetes.default.svc port=443
│ [2023/10/16 16:05:00] [ info] [filter:kubernetes:kubernetes.0]  token updated
│ [2023/10/16 16:05:00] [ info] [filter:kubernetes:kubernetes.0] local POD info OK
│ [2023/10/16 16:05:00] [ info] [filter:kubernetes:kubernetes.0] testing connectivity with API server...
│ [2023/10/16 16:05:00] [ info] [filter:kubernetes:kubernetes.0] connectivity OK
│ [2023/10/16 16:05:00] [ info] [output:es:es.0] worker #0 started
│ [2023/10/16 16:05:00] [ info] [output:es:es.0] worker #1 started
│ [2023/10/16 16:05:00] [ info] [http_server] listen iface=0.0.0.0 tcp_port=2020
│ [2023/10/16 16:05:00] [ info] [sp] stream processor started
│ [2023/10/16 16:05:00] [ info] [input:tail:tail.0] inotify_fs_add(): inode=41916664 watch_fd=1 name=/var/log/containers/backend-api-deployment-57d68dd4f5-djn8x_backend-dev_backend-api-f950104ab9f300586803316ad7beef5c9506db9fceeb4af0dc0575b3b9bacfd7.log
│ [2023/10/16 16:05:00] [ info] [input:tail:tail.0] inotify_fs_add(): inode=17488499 watch_fd=2 name=/var/log/containers/backend-api-deployment-6dc5b97645-tqwxh_backend-staging_backend-api-23f14f74af6cc163f233499ba92a2746cb2f263c9379ba53fc47cd3d76e00bbb.log
...
│ [2023/10/17 04:49:01] [error] [output:es:es.0] HTTP status=429 URI=/_bulk, response:
│ 429 Too Many Requests /_bulk
│
│ [2023/10/17 04:49:01] [ warn] [engine] failed to flush chunk '1-1697518140.870529031.flb', retry in 6 seconds: task_id=1, input=tail.0 > output=es.0 (out_id=0)
│ [2023/10/17 04:49:01] [error] [output:es:es.0] HTTP status=429 URI=/_bulk, response:
│ 429 Too Many Requests /_bulk
│
│ [2023/10/17 04:49:01] [ warn] [engine] failed to flush chunk '1-1697518140.276173730.flb', retry in 7 seconds: task_id=0, input=tail.0 > output=es.0 (out_id=0)
│ [2023/10/17 04:49:07] [ info] [engine] flush chunk '1-1697518140.870529031.flb' succeeded at retry 1: task_id=1, input=tail.0 > output=es.0 (out_id=0)
│ [2023/10/17 04:49:08] [ info] [engine] flush chunk '1-1697518140.276173730.flb' succeeded at retry 1: task_id=0, input=tail.0 > output=es.0 (out_id=0)
│ [2023/10/17 05:08:50] [ info] [input:tail:tail.0] inotify_fs_add(): inode=37547666 watch_fd=8 name=/var/log/containers/backend-api-deployment-5d9fc55496-8mppx_backend-dev_backend-api-839c128d6227f797722496a992ca9149b95c366997c2b1ec28ceb65490582e3b.log
│ [2023/10/17 05:08:52] [ info] [filter:kubernetes:kubernetes.0]  token updated
│ [2023/10/17 05:09:25] [ info] [input:tail:tail.0] inotify_fs_remove(): inode=41916664 watch_fd=1
│ [2023/10/17 05:09:37] [ info] [input:tail:tail.0] inotify_fs_remove(): inode=17488499 watch_fd=2

有趣的是，如果所有的流利位守护进程被手动杀死并通过自我修复复活，它们都会暂时再次正常收集。

之后，如果再次更新并重新加载Service Pod，则会再次出现相同的问题。

是什么原因导致这个问题呢？我该如何修复它？如果有任何推荐的 Fluent-bit 设置，欢迎提供额外的建议。

谢谢你！

logging

1 个回答

  1. Best Answer

    我找不到明确的原因，但我想我找到了解决方案，所以我与您分享。

    在Kibana中检查日志时，记录了各种时间戳，但是从附图中可以看到，Fluent-bit直接记录的时间戳存在问题。

    不过，考虑到一旦 Fluent-bit 重启 Pod，一切就恢复正常，很难认为我的 Config 是错误的。

    因此，我考虑从我的应用程序日志中解析时间信息，继续输出正常时间，并直接指定时间，而不是使用@timestampFluent-bit 记录的默认时间。

    我声明了一个解析器，如下所示，使用解析时间信息的正则表达式从日志中的字符串中提取值，然后使用Time_Key.

    [PARSER] 
        Name log_timestamp
        Format regex
        Regex ^(?<log_time>[^\s]+)
        Time_Key log_time
        Time_Format %Y-%m-%dT%H:%M:%S.%LZ
        Time_Keep On

    上面的解析器是使用过滤器管道中的解析器过滤器来操作的。

        [FILTER]
        Name parser
        Match kube.*
        Key_Name log
        Parser log_timestamp 
        Preserve_Key On
        Reserve_Data On

    换句话说，完整配置如下。

    config:
  inputs: |
    [INPUT]
        Name tail
        Path /var/log/containers/*.log
        Tag kube.*
        Mem_Buf_Limit 50MB
        Refresh_Interval 10
        multiline.parser python-custom

  outputs: |
    [OUTPUT]
        Name            es
        Match           kube.*
        Host            ${es_domain_name}
        Port            443
        TLS             On
        AWS_Auth        On
        AWS_Region      ${region}
        Retry_Limit     6
        Replace_Dots    On
        Trace_Error     On    

  filters: |
    [FILTER]
        Name kubernetes
        Match kube.*
        Merge_Log On
        Merge_Log_Key       log_processed
        Keep_Log Off
        K8S-Logging.Parser On
        K8S-Logging.Exclude On
    
    [FILTER]
        Name parser
        Match kube.*
        Key_Name log
        Parser log_timestamp 
        Preserve_Key On
        Reserve_Data On

  customParsers: |
    [MULTILINE_PARSER]
        name          python-custom
        type          regex
        flush_timeout 1000
        rule      "start_state"   "/stderr F(.*)/"  "cont"
        rule      "cont"          "/stderr F(.*)/"  "cont"
    
    [PARSER] 
        Name log_timestamp
        Format regex
        Regex ^(?<log_time>[^\s]+)
        Time_Key log_time
        Time_Format %Y-%m-%dT%H:%M:%S.%LZ
        Time_Keep On
    • 0

相关问题