写于2022-01-03
Kubernetes
23 分钟 读完 (大约 3481 个字) 0次访问

Fluentd 性能优化

之前我们已经在k8s集群中搭建好日志收集系统了，但是经过测试后性能很差，在设置Fulentd的最大资源是800M内存，1核CPU后进行压测，1秒中能处理并推送大约1500条日志，需要调优以提高性能。

English version

1、如何测试

首先简单描述一下我是如何测试Fluentd的性能。

随便新建一个简单的Java Boot应用，或者修改一个现有的应用，然后在SpringBootApplication类中进行修改。

1、修改SpringApplication

将：

1
2
3
public static void main(String[] args) {
    SpringApplication.run(Application.class, args);
}

修改为：

1
2
3
4
5
6
7
8
9
10
public static void main(String[] args) {
    while (true){
        log.info("test test test test test test test test test test test");
    try {
        Thread.sleep(10);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
  }
}

Thread.sleep(10); 用来粗略控制每秒打印的日志条数。1s=1000ms，如果每次循环sleep 10ms，那么1s中大概打印日志100条。如果每次循环sleep 1ms，那么1s中大概打印日志1000条。如果想增加打印日志条数，可以多copy几个log.info。如果按如下所示，大概一秒打印日志2w条。

1
2
3
4
5
6
7
8
9
10
11
12
public static void main(String[] args) {
    while (true){
        for(int i = 0 ; i < 20; i++){
            log.info("test test test test test test test test test test test");
        }
    try {
        Thread.sleep(1);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
  }
}

然后将Java应用打成Docker镜像，部署在k8s中。启动应用，就会一直打印日志了。通过对比Fluentd中的日志，可以得到每秒处理、发送的日志条数，就能知道Fluentd的性能情况了。

2、修改log_level为debug

在Fluentd的配置文件中，要将<match **> @id kafka 中的@log_level 修改为debug。这样在log中可以查看到具体推送了多少日志到Kafka，类似于。

2022-01-01 03:31:41 +0000 [debug]: #0 [kafka] 2000 messages send.

然后我们查看<match **> @id kafka 中的<buffer>模块中flush_interval 的值，这个代表了推送的频率。

3、计算性能

如果Fluentd log中日志显示[kafka] 2000 messages send，同时flush_interval设置为10s，那就代表10s处理并推送了2000条日志，也就是性能为200条/S。

2、调优思路

看到性能很差后，首先我去搜了一下Fluentd的性能峰值大概是多少，确定一下是插件本身的性能问题还是我们配置的问题。查看完官方文档后，可以看到最少性能也应该在5000条/S，说明是我们配置的有问题，接下来就是进行性能调优。

3、问题定位

1、无插件性能测试

我们在配置Fluentd的时候添加了很多的插件，比如detect_exceptions用来合并Exception、concat用来合并多行日志、kubernetes_metadata用来添加k8s集群信息、record_transformer用来增删改字段。那么会不会是这些插件导致了Fluentd的性能较差。或者换句话说，如果只有读取日志+推送，去掉其他所有逻辑，Fluentd的性能峰值能达到多少？ 集群中Fluentd flush_interval 设置为10S。

修改配置文件如下，进行测试。

查看log文件：

1
2
3
4
5
6
7
8
9
10
2022-01-01 04:14:26 +0000 [debug]: #0 [kafka] 43250 messages send.
2022-01-01 04:14:36 +0000 [debug]: #0 [kafka] 38101 messages send.
2022-01-01 04:14:47 +0000 [debug]: #0 [kafka] 43251 messages send.
2022-01-01 04:14:57 +0000 [debug]: #0 [kafka] 43250 messages send.
2022-01-01 04:15:07 +0000 [debug]: #0 [kafka] 39131 messages send.
2022-01-01 04:15:18 +0000 [debug]: #0 [kafka] 39131 messages send.
2022-01-01 04:15:28 +0000 [debug]: #0 [kafka] 42221 messages send.
2022-01-01 04:15:37 +0000 [debug]: #0 [kafka] 38101 messages send.
2022-01-01 04:15:48 +0000 [debug]: #0 [kafka] 43250 messages send.
2022-01-01 04:15:57 +0000 [debug]: #0 [kafka] 38102 messages send.

感觉差不多也就4000条/S，这个性能感觉也很一般，因为官网给的文档是如果达到5000条/S的时候需要优化，说明5000条/S应该是很容易达到的。

2、tail问题定位

经过排查，最终发现问题出在json时间解析上：

time_format %Y-%m-%dT%H:%M:%S.%NZ

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:07:03 +0000 [debug]: #0 [kafka] 119892 messages send.
2022-01-01 05:07:19 +0000 [debug]: #0 [kafka] 509786 messages send.
2022-01-01 05:07:31 +0000 [debug]: #0 [kafka] 129708 messages send.
2022-01-01 05:07:39 +0000 [debug]: #0 [kafka] 44242 messages send.
2022-01-01 05:07:44 +0000 [debug]: #0 [kafka] 109599 messages send.
2022-01-01 05:07:59 +0000 [debug]: #0 [kafka] 469568 messages send.
2022-01-01 05:08:13 +0000 [debug]: #0 [kafka] 135742 messages send.
2022-01-01 05:08:16 +0000 [debug]: #0 [kafka] 53292 messages send.
2022-01-01 05:08:30 +0000 [debug]: #0 [kafka] 435380 messages send.
2022-01-01 05:08:43 +0000 [debug]: #0 [kafka] 134736 messages send.

去掉这句话，性能有非常大的提升。经过计算，速度能达到21000条/S，因为我们设置的打印日志基本上也是2W左右/S，所以不确定是否已经达到了FLuentd的性能峰值，但是能看出来性能提升了5倍。

这句话具体的作用是将time这个字段格式化成%Y-%m-%dT%H:%M:%S.%NZ格式。其实我们的使用场景是用不上这个字段的，跟时间有关的只有在Kibana页面中有一个计算kafka消息delay的地方会用到kafka推送时间。kafka的推送时间是可以设置的，使用FLuentd事件事件或者当前时间。

同时我们Java项目日志都是通过插件输出的，日志都是以时间开头的，所以不需要再对time这个字段进行时间格式化。可以删除以提高性能。

3、去掉时间解析性能测试

那么如果加上全量插件，性能能达到多少呢？如果能达到7000条左右，那么就不需要再调优了。

经过测试，发现只有3000条左右，那说明加上插件，性能上有非常大影响的。接下来目标很明确了。排查出具体哪个插件的影响较大。

1
2
3
4
5
6
7
8
9
10
11
12
13
2022-01-01 04:21:27 +0000 [debug]: #0 [kafka] 31921 messages send.
2022-01-01 04:21:37 +0000 [debug]: #0 [kafka] 33981 messages send.
2022-01-01 04:21:46 +0000 [debug]: #0 [kafka] 29862 messages send.
2022-01-01 04:21:56 +0000 [debug]: #0 [kafka] 32952 messages send.
2022-01-01 04:22:07 +0000 [debug]: #0 [kafka] 33980 messages send.
2022-01-01 04:22:16 +0000 [debug]: #0 [kafka] 29863 messages send.
2022-01-01 04:22:27 +0000 [debug]: #0 [kafka] 33981 messages send.
2022-01-01 04:22:36 +0000 [debug]: #0 [kafka] 30892 messages send.
2022-01-01 04:22:47 +0000 [debug]: #0 [kafka] 33980 messages send.
2022-01-01 04:22:56 +0000 [debug]: #0 [kafka] 31921 messages send.
2022-01-01 04:23:07 +0000 [debug]: #0 [kafka] 33981 messages send.
2022-01-01 04:23:19 +0000 [debug]: #0 [kafka] 35011 messages send.
2022-01-01 04:23:28 +0000 [debug]: #0 [kafka] 30891 messages send.

4、插件性能测试

逻辑很简单，把所有的插件全部删除，只保留数据的输入(tail)和输出(kafka)模块，然后一个一个添加我们现有的插件进行尝试，看看添加哪个插件会对性能有较大影响。

1、只要detect_exceptions

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:05:19 +0000 [debug]: #0 [kafka] 97003 messages send.
2022-01-01 05:05:24 +0000 [debug]: #0 [kafka] 91186 messages send.
2022-01-01 05:05:38 +0000 [debug]: #0 [kafka] 89283 messages send.
2022-01-01 05:05:48 +0000 [debug]: #0 [kafka] 93693 messages send.
2022-01-01 05:05:58 +0000 [debug]: #0 [kafka] 86792 messages send.
2022-01-01 05:06:07 +0000 [debug]: #0 [kafka] 79343 messages send.
2022-01-01 05:06:18 +0000 [debug]: #0 [kafka] 99481 messages send.
2022-01-01 05:06:28 +0000 [debug]: #0 [kafka] 86697 messages send.
2022-01-01 05:06:38 +0000 [debug]: #0 [kafka] 92506 messages send.
2022-01-01 05:06:48 +0000 [debug]: #0 [kafka] 93030 messages send

如果只保留detect_exceptions插件的话，经过测试可以看到性能差不多在9000条左右/S。对比峰值2.1W条，降低了50%左右的性能，说明这个插件的性能不是很好。

2、只要concat

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:37:39 +0000 [debug]: #0 [kafka] 232269 messages send.
2022-01-01 05:37:48 +0000 [debug]: #0 [kafka] 136747 messages send.
2022-01-01 05:38:01 +0000 [debug]: #0 [kafka] 275506 messages send.
2022-01-01 05:38:10 +0000 [debug]: #0 [kafka] 123676 messages send.
2022-01-01 05:38:20 +0000 [debug]: #0 [kafka] 239307 messages send.
2022-01-01 05:38:29 +0000 [debug]: #0 [kafka] 143786 messages send.
2022-01-01 05:38:41 +0000 [debug]: #0 [kafka] 279529 messages send.
2022-01-01 05:38:50 +0000 [debug]: #0 [kafka] 119654 messages send.
2022-01-01 05:39:00 +0000 [debug]: #0 [kafka] 231264 messages send.
2022-01-01 05:39:10 +0000 [debug]: #0 [kafka] 174957 messages send.

如果只保留concat插件的话，经过计算，性能在19600条/S，基本跟峰值2.1W条差别不大，说明这个插件性能很高。

3、只要kubernetes_metadata

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:13:00 +0000 [debug]: #0 [kafka] 85467 messages send.
2022-01-01 05:13:12 +0000 [debug]: #0 [kafka] 101555 messages send.
2022-01-01 05:13:23 +0000 [debug]: #0 [kafka] 105578 messages send.
2022-01-01 05:13:32 +0000 [debug]: #0 [kafka] 105577 messages send.
2022-01-01 05:13:40 +0000 [debug]: #0 [kafka] 92505 messages send.
2022-01-01 05:13:53 +0000 [debug]: #0 [kafka] 94517 messages send.
2022-01-01 05:14:05 +0000 [debug]: #0 [kafka] 97533 messages send.
2022-01-01 05:14:10 +0000 [debug]: #0 [kafka] 96527 messages send.
2022-01-01 05:14:26 +0000 [debug]: #0 [kafka] 100550 messages send.
2022-01-01 05:14:37 +0000 [debug]: #0 [kafka] 98538 messages send.

如果只保留kubernetes_metadata插件的话，经过测试可以看到性能差不多在9k-1w条左右/S。这个插件的性能也比较一般。

4、kubernetes_metadata + record_transformer

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:14:52 +0000 [debug]: #0 [kafka] 70385 messages send.
2022-01-01 05:14:53 +0000 [debug]: #0 [kafka] 80440 messages send.
2022-01-01 05:15:06 +0000 [debug]: #0 [kafka] 94517 messages send.
2022-01-01 05:15:19 +0000 [debug]: #0 [kafka] 90495 messages send.
2022-01-01 05:15:24 +0000 [debug]: #0 [kafka] 80440 messages send.
2022-01-01 05:15:36 +0000 [debug]: #0 [kafka] 94517 messages send.
2022-01-01 05:15:48 +0000 [debug]: #0 [kafka] 89489 messages send.
2022-01-01 05:15:53 +0000 [debug]: #0 [kafka] 88484 messages send.
2022-01-01 05:16:08 +0000 [debug]: #0 [kafka] 87478 messages send.
2022-01-01 05:16:20 +0000 [debug]: #0 [kafka] 86473 messages send.

由于record_transformer是对字段进行增删改等操作，是基于kubernetes_metadata的。所以只能在kubernetes_metadata的基础上测试record_transformer的性能。

可以看到性能在8k-9k左右/S，对比不添加record_transformer性能来比，性能只降低了10%左右，说明record_transformer性能很高。

5、去掉插件

1、去掉detect_exceptions插件

detect_exceptions这个插件的作用是将日志中的多行Exception合并成一行，可以检测Java等语言。

concat的原理就很简单粗暴了，对日志进行正则匹配，然后合并多行日志。

原理很简单，就是对日志的开头进行正则匹配，我们在插件中设置的正则为：
/^[\[ ]*\d{1,4}[-\/ ]+\d{1,2}[-\/ ]+\d{1,4}[ T]+\d{1,2}:\d{1,2}:\d{1,2}/

因为正常的日志都是以时间开头。如果存在多行日志：一行时间开头的日志+多行没有时间开头的日志+一行带时间开头的日志。那么其实应该只有两行日志，一行有时间+多行没时间应该是一条日志。

放个示例更容易理解：

1
2
3
4
5
6
7
2022-01-01 05:38:50 +0000 [debug]: console config
a=1
b=2
c=3
c=4
d=5
2022-01-01 05:38:50 +0000 [debug]: #0 [kafka] 119654 messages send.

其实只有两行日志：

1
2
3
4
5
6
7
8
9
2022-01-01 05:38:50 +0000 [debug]: console config
a=1
b=2
c=3
c=4
d=5


2022-01-01 05:38:50 +0000 [debug]: #0 [kafka] 119654 messages send.

但是仔细想想，Exception不也是这种情况吗？

所以其实concat插件已经包含detect_exceptions的功能了，但是有一点需要特殊处理，就是k8s集群中的项目打印日志都需要使用能被正则表达式匹配的日志格式，否则就无法被合并对行日志。

但是这个问题不大，我们可以出一个规范，在我们集群中的项目的日志应该格式化为某格式。

这样我们就可以删除detect_exceptions插件，以提高性能。

2、去掉kubernetes_metadata插件

那能不能想办法去掉kubernetes_metadata这个插件呢？

kubernetes_metadata这个插件的作用是给日志中添加一些pod相关的信息：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
{
    "docker": {
    "container_id": ""
},
"kubernetes": {
    "container_name": "",
    "namespace_name": "",
    "pod_name": "",
    "container_image": "",
    "container_image_id": "",
    "pod_id": "",
    "pod_ip": "",
    "host": "",
    "labels": {
        "pod-template-hash": "",
        "k8s_kuboard_cn/layer": "",
        "k8s_kuboard_cn/name": ""
    },
    "master_url": "",
    "namespace_id": "",
    "namespace_labels": {
        "alertmanager": "",
        "kubernetes_io/metadata_name": ""
        }
    }
}

但是很多都是涉及到k8s集群的相关信息，是需要删除的，实际上我们都用不上。我们唯一能用到的就是在Kibana页面中通过某个标识来查询日志，比如pod_id、container_name、namespace_name等。

但是这个信息在tag这个字段里面是存在的。tag的值包含[podName][nameSpace][deploymentName]-[containerId]，其实信息已经足够了。

我们在配置文件中添加tag ${tag_parts[4]}，然后我们在Kibana中就可以通过tag : podName or tag : containerId 来查询日志了。

这样我们就可以删除掉kubernetes_metadata这个插件了。

6、新配置文件性能测试

我们删除了detect_exceptions和kubernetes_metadata这两个插件，每个插件基本上都能使性能降低50%。然后修改了一下其他的插件，下面是修改后的最终版配置文件：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
apiVersion: v1
kind: ConfigMap
metadata:
  name: fluentd-config
  namespace: kube-system
data:
  
  fluent.conf: |
    <source>
      @type tail
      path /var/log/containers/*.log              # 挂载的服务器Docker容器日志地址
      exclude_path ["/var/log/containers/kube-*.log", "/var/log/containers/test-*.log", "/var/log/containers/calico-*.log", "/var/log/containers/heapster-*.log", "/var/log/containers/etcd-*.log", "/var/log/containers/kubernetes-*.log", "/var/log/containers/fluentd-*.log"]          # 排除的日志文件
      follow_inodes true                          # 如果没有这个参数，文件轮转会导致日志重复
      pos_file /var/log/es-containers.log.pos     # 保存已读日志文件的位置
      tag raw.kubernetes.*                        # 日志标签
      format none                                 
    </source>
    
    <filter raw.**>
      @type parser 																# JSON解析器
      key_name message
      <parse>
        @type json
      </parse>
    </filter>

    <filter raw.**>
      @type concat
      key log                                     # 扫描JOSN格式日志的字段名
      stream_identity_key container_id # 确定事件属于哪个流
      multiline_start_regexp /^[\[ ]*\d{1,4}[-\/ ]+\d{1,2}[-\/ ]+\d{1,4}[ T]+\d{1,2}:\d{1,2}:\d{1,2}/                       # 匹配多行开头的正则表达式
      separator ""                                # 多行的分隔符
      flush_interval 1                           # 刷新最后收到的事件日志之前的秒数
      timeout_label @NORMAL                       # 如果事件超时，打上NORMAL标签
    </filter>

    # 像处理普通日志一样处理超时日志行
    <match **>
      @type relabel
      @label @NORMAL
    </match>

    <label @NORMAL>
      <filter kubernetes.**>
        @type record_transformer
        enable_ruby true                          # 使用${record[""]}启用Ruby语法
        <record>
          message ${record["log"]}                # 将log字段重命名为message
          # 这里也可以添加字段，比如添加source:test
          source test
          tag ${tag_parts[4]}
        </record>
        # 删除多余的字段
        remove_keys $.log,$.stream                           
      </filter>

      <match **>                                  # 匹配所有数据都输出到kfaka
        @id kafka                                 # 标识符，非必需
        @type kafka2                              # 输出插件的类型
        @log_level debug                          # 捕获日志的级别，这里为了查看发送的性能，设置为debug
        # list of seed brokers
        brokers brokers                           # brokers地址
        topic_key topic_key                       # topic_key
        default_topic topic_key                   # topic_key
        use_event_time true                       # 将Fluentd时间设置为Kafka的CreateTime
        # buffer settings
        <buffer>                                  # Fluentd可以使用缓存来提高性能
            @type file
            path /var/log/fluentd-buffers/kubernetes.system.buffer # 缓存文件路径

            flush_mode interval                   # 刷新类型
            flush_thread_count 16                 # 刷新线程个数
            flush_interval 10s                    # 刷新间隔
            retry_max_interval 30                 # 失败重试的最长间隔

            chunk_limit_size 256M                 # 单个缓存文件的最大大小
            queue_limit_length 16                 # 最多缓存文件个数
            overflow_action drop_oldest_chunk     # 当缓存队列已满的拒绝策略
        </buffer>
        # data type settings
        <format>
            @type json                            # JSON解析器
        </format>
        required_acks -1                          # 请求是否需要确认
        compression_codec gzip                    # 生产者用于压缩消息的解编码器
      </match>
    </label>

经过测试，性能能达到9000+/S，已经超过了预期的目标。

1
2
3
4
5
6
7
8
9
10
2022-01-01 05:16:48 +0000 [debug]: #0 [kafka] 98538 messages send.
2022-01-01 05:16:55 +0000 [debug]: #0 [kafka] 83456 messages send.
2022-01-01 05:17:01 +0000 [debug]: #0 [kafka] 94517 messages send.
2022-01-01 05:17:12 +0000 [debug]: #0 [kafka] 96527 messages send.
2022-01-01 05:17:22 +0000 [debug]: #0 [kafka] 91501 messages send.
2022-01-01 05:17:32 +0000 [debug]: #0 [kafka] 95522 messages send.
2022-01-01 05:17:42 +0000 [debug]: #0 [kafka] 88484 messages send.
2022-01-01 05:17:51 +0000 [debug]: #0 [kafka] 85468 messages send.
2022-01-01 05:18:01 +0000 [debug]: #0 [kafka] 92346 messages send.
2022-01-01 05:18:12 +0000 [debug]: #0 [kafka] 91542 messages send.

7、回顾总结

经过我们调优后，性能翻了3倍。我们的思路也很明确，先查看Fluentd这个组件大概性能是多少，来定位问题是我们配置问题还是Fluentd自身的瓶颈，确认是我们配置的问题后，那么思路就变成了去寻找性能不好的插件，然后思考能不能删除或者替换其他性能更优的插件。这么一步一步下来，最终的性能还是比较满意。

同时由于Fluentd是使用Ruby开发，Ruby 有 GIL（全局解释器锁），它一次只允许一个线程执行，所以性能是有瓶颈的。如果对Fluentd有更高的性能要求，可以参考官方文档，使用多W


# Fluentd, Kubernetes

喜欢这篇文章？打赏一下作者吧

Fluentd Performance Tuning
DolphinScheduler Start Docker & Kubernetes Config Data Injection Ideas

评论

关注我

友情链接

分类

最新文章

归档

标签

.NET 1
Cisco 2
Docker 6
DolphinScheduler 11
E2E 2
Fluentd 4
Hexo 4
Java 2
Jenkins 2
Kubernetes 12
Laravel 1
Linux 1
Mysql 1
Nginx 1
PHP 3
Prometheus 2
Python 2
Quartz 2
Scala 2
Spring 1
WordPress 3
Your browser is out-of-date!

Update your browser to view this website correctly. Update my browser now

×