ICode9

精准搜索请尝试: 精确搜索
首页 > 其他分享> 文章详细

Fluentd 使用 multiline 解析器来处理多行日志

2022-06-24 11:33:49  阅读:197  来源: 互联网

标签:解析器 Fluentd 12 06 fluentd 0000 multiline 2022 20


转载自:https://mp.weixin.qq.com/s?__biz=MzU4MjQ0MTU4Ng==&mid=2247500439&idx=1&sn=45e9e0e0ef4e41ed52d9b1bf81d2879d&chksm=fdbacd8acacd449c3ea56432a1e89e48441482905687c020c59af7bcf64e4edfbb8bebf945b6&cur_album_id=1837018771551485956&scene=190#rd

日志收集的时候多行日志一直是一个比较头疼的问题,开发人员并不愿意将日志以 JSON 的方式进行输出,那么就只能在收集日志的时候去重新对日志做下结构化了。

由于日志采集器的实现方式和标准不一样,所以具体如何处理多行日志不同的采集器也会不一样的,比如这里我们使用 Fluentd 来作为日志采集器,那么我们就可以使用 multiline 这个解析器来处理多行日志。

多行解析器使用 formatN 和 format_firstline 参数解析日志,format_firstline 用于检测多行日志的起始行。formatN,其中 N 的范围是 [1..20],是多行日志的 Regexp 格式列表。

测试数据

比如现在我们有如下所示的多行日志数据:

2022-06-20 19:32:07.264 DEBUG 7 [TID:bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125] --- [   scheduling-4] o.s.d.redis.core.RedisConnectionUtils    : Closing Redis Connection.
2022-06-20 19:32:07.264 DEBUG 7 [TID:bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125] --- [   scheduling-4] io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=DEL, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2022-06-20 17:28:27.871 DEBUG 6 [TID:N/A] --- [           main] o.h.l.p.build.spi.LoadPlanTreePrinter    : LoadPlan(entity=com.xxxx.entity.ScheduledLeadsInvalid)
    - Returns
       - EntityReturnImpl(entity=com.xxxx.entity.ScheduledLeadsInvalid, querySpaceUid=<gen:0>, path=com.xxxx.entity.ScheduledLeadsInvalid)
    - QuerySpaces
       - EntityQuerySpaceImpl(uid=<gen:0>, entity=com.xxxx.entity.ScheduledLeadsInvalid)
          - SQL table alias mapping - scheduledl0_
          - alias suffix - 0_
          - suffixed key columns - {id1_51_0_}
2022-06-20 19:32:47.062 DEBUG 7 [TID:N/A] --- [nection-cleaner] h.i.c.PoolingHttpClientConnectionManager : Closing connections idle longer than 60000 MILLISECONDS

首先创建一个 fluentd 目录,在下面创建用于保存 fluentd 的配置文件 etc 目录和保存日志的 logs 目录,将上面的测试日志保存在 logs/test.log 文件中

$ mkdir fluentd
$ cd fluentd
# 创建用于保存 fluentd 的配置文件 etc 目录和保存日志的 logs 目录
$ mkdir -p etc logs

常规解析

然后创建一个用于解析日志的 fluentd 配置文件 etcd/fluentd_basic.conf,内容如下所示:

<source>
  @type tail
  path /fluentd/logs/*.log
  pos_file /fluentd/logs/test.log.pos
  tag test.logs
  read_from_head true
  <parse>
    @type regexp
    expression /^(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+) (?<pid>[^s+]+) \[TID:(?<tid>[,a-z0-9A-Z./]+)\] --- \[(?<thread>.*)\] (?<message>[\s\S]*)/ 
  </parse>
</source>
<match **>
  @type stdout
</match>

然后我们使用 docker 镜像的方式来启动 fluentd 解析我们的日志:

$ docker run --rm -v $(pwd)/etc:/fluentd/etc -v $(pwd)/logs:/fluentd/logs fluent/fluentd:v1.14-1 -c /fluentd/etc/fluentd_basic.conf -v

fluentd -c /fluentd/etc/fluentd_basic.conf -v
2022-06-20 12:31:17 +0000 [info]: fluent/log.rb:330:info: parsing config file is succeeded path="/fluentd/etc/fluentd_basic.conf"
2022-06-20 12:31:17 +0000 [info]: fluent/log.rb:330:info: gem 'fluentd' version '1.14.3'
2022-06-20 12:31:17 +0000 [warn]: fluent/log.rb:351:warn: define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2022-06-20 12:31:17 +0000 [info]: fluent/log.rb:330:info: using configuration file: <ROOT>
  <source>
    @type tail
    path "/fluentd/logs/*.log"
    pos_file "/fluentd/logs/test.log.pos"
    tag "test.logs"
    read_from_head true
    <parse>
      @type "regexp"
      expression /^(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+) (?<pid>[^s+]+) \[TID:(?<tid>[,a-z0-9A-Z./]+)\] --- \[(?<thread>.*)\] (?<message>[\s\S]*)/
      unmatched_lines 
    </parse>
  </source>
  <match **>
    @type stdout
  </match>
</ROOT>
2022-06-20 12:36:21 +0000 [info]: fluent/log.rb:330:info: starting fluentd-1.14.3 pid=10 ruby="2.7.5"
2022-06-20 12:36:21 +0000 [info]: fluent/log.rb:330:info: spawn command to main:  cmdline=["/usr/bin/ruby", "-Eascii-8bit:ascii-8bit", "/usr/bin/fluentd", "-c", "/fluentd/etc/fluentd_basic.conf", "-v", "--plugin", "/fluentd/plugins", "--under-supervisor"]
2022-06-20 12:36:22 +0000 [info]: fluent/log.rb:330:info: adding match pattern="**" type="stdout"
2022-06-20 12:36:22 +0000 [info]: fluent/log.rb:330:info: adding source type="tail"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2022-06-20 12:36:22 +0000 [info]: #0 fluent/log.rb:330:info: starting fluentd worker pid=19 ppid=10 worker=0
2022-06-20 12:36:22 +0000 [debug]: #0 fluent/log.rb:309:debug: tailing paths: target = /fluentd/logs/test.log | existing = 
2022-06-20 12:36:22 +0000 [info]: #0 fluent/log.rb:330:info: following tail of /fluentd/logs/test.log
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "    - Returns"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "       - EntityReturnImpl(entity=com.xxxx.entity.ScheduledLeadsInvalid, querySpaceUid=<gen:0>, path=com.xxxx.entity.ScheduledLeadsInvalid)"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "    - QuerySpaces"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "       - EntityQuerySpaceImpl(uid=<gen:0>, entity=com.xxxx.entity.ScheduledLeadsInvalid)"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "          - SQL table alias mapping - scheduledl0_"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "          - alias suffix - 0_"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: "          - suffixed key columns - {id1_51_0_}"
2022-06-20 12:36:22 +0000 [warn]: #0 fluent/log.rb:351:warn: pattern not matched: ""
2022-06-20 12:36:22.308970489 +0000 test.logs: {"timestamp":"2022-06-20 19:32:07.264","level":"DEBUG","pid":"7","tid":"bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125","thread":"   scheduling-4","message":"o.s.d.redis.core.RedisConnectionUtils    : Closing Redis Connection."}
2022-06-20 12:36:22.309013403 +0000 test.logs: {"timestamp":"2022-06-20 19:32:07.264","level":"DEBUG","pid":"7","tid":"bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125","thread":"   scheduling-4","message":"io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=DEL, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]"}
2022-06-20 12:36:22.309025559 +0000 test.logs: {"timestamp":"2022-06-20 17:28:27.871","level":"DEBUG","pid":"6","tid":"N/A","thread":"           main","message":"o.h.l.p.build.spi.LoadPlanTreePrinter    : LoadPlan(entity=com.xxxx.entity.ScheduledLeadsInvalid)"}
2022-06-20 12:36:22.309715537 +0000 test.logs: {"timestamp":"2022-06-20 19:32:47.062","level":"DEBUG","pid":"7","tid":"N/A","thread":"nection-cleaner","message":"h.i.c.PoolingHttpClientConnectionManager : Closing connections idle longer than 60000 MILLISECONDS"}
2022-06-20 12:36:22 +0000 [info]: #0 fluent/log.rb:330:info: fluentd worker is now running worker=0
2022-06-20 12:36:22.305753588 +0000 fluent.info: {"pid":19,"ppid":10,"worker":0,"message":"starting fluentd worker pid=19 ppid=10 worker=0"}
2022-06-20 12:36:22.308522121 +0000 fluent.debug: {"message":"tailing paths: target = /fluentd/logs/test.log | existing = "}
2022-06-20 12:36:22.308751095 +0000 fluent.info: {"message":"following tail of /fluentd/logs/test.log"}
2022-06-20 12:36:22.309047520 +0000 fluent.warn: {"message":"pattern not matched: \"    - Returns\""}
2022-06-20 12:36:22.309180634 +0000 fluent.warn: {"message":"pattern not matched: \"       - EntityReturnImpl(entity=com.xxxx.entity.ScheduledLeadsInvalid, querySpaceUid=<gen:0>, path=com.xxxx.entity.ScheduledLeadsInvalid)\""}
2022-06-20 12:36:22.309258667 +0000 fluent.warn: {"message":"pattern not matched: \"    - QuerySpaces\""}
2022-06-20 12:36:22.309328608 +0000 fluent.warn: {"message":"pattern not matched: \"       - EntityQuerySpaceImpl(uid=<gen:0>, entity=com.xxxx.entity.ScheduledLeadsInvalid)\""}
2022-06-20 12:36:22.309401309 +0000 fluent.warn: {"message":"pattern not matched: \"          - SQL table alias mapping - scheduledl0_\""}
2022-06-20 12:36:22.309468557 +0000 fluent.warn: {"message":"pattern not matched: \"          - alias suffix - 0_\""}
2022-06-20 12:36:22.309563730 +0000 fluent.warn: {"message":"pattern not matched: \"          - suffixed key columns - {id1_51_0_}\""}
2022-06-20 12:36:22.309723704 +0000 fluent.warn: {"message":"pattern not matched: \"\""}
2022-06-20 12:36:22.310086626 +0000 fluent.info: {"worker":0,"message":"fluentd worker is now running worker=0"}

从上面的解析结果可以看出,正则表达式有一部分没匹配,有一些可以正常解析,比如下面的日志就是前面的一行日志解析出来后的结果:

{"timestamp":"2022-06-20 19:32:07.264","level":"DEBUG","pid":"7","tid":"bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125","thread":"   scheduling-4","message":"o.s.d.redis.core.RedisConnectionUtils    : Closing Redis Connection."}

而没有正常匹配的是多行日志,fluentd 会将每一个日志行当成独立的一行进行处理,这显然不符合我们的预期。

多行解析器

我们希望的是能将多行日志当成一行日志进行处理,这里就需要用到 multiline 这个解析器了,新建一个用于多行日志处理的配置文件 etc/fluentd_multline.conf,内容如下所示:

<source>
  @type tail
  path /fluentd/logs/*.log
  pos_file /fluentd/logs/test.log.pos
  tag test.logs
  read_from_head true
  <parse>
    @type multiline
    format_firstline /\d{4}-\d{1,2}-\d{1,2}/
    format1 /^(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+) (?<pid>[^s+]+) \[TID:(?<tid>[,a-z0-9A-Z./]+)\] --- \[(?<thread>.*)\] (?<message>[\s\S]*)/ 
  </parse>
</source>
<match **>
  @type stdout
</match>

这里面我们使用 format_firstline /\d{4}-\d{1,2}-\d{1,2}/ 来匹配每一行日志的开头,format1 用来解析第一行日志,如果你还有更多数据需要匹配,则可以继续配置第二行 format2 的匹配规则等等,使用上面这个配置重新启动 fluentd:

docker run --rm -v $(pwd)/etc:/fluentd/etc -v $(pwd)/logs:/fluentd/logs fluent/fluentd:v1.14-1 -c /fluentd/etc/fluentd_multline.conf -v
fluentd -c /fluentd/etc/fluentd_multline.conf -v
2022-06-20 12:41:58 +0000 [info]: fluent/log.rb:330:info: parsing config file is succeeded path="/fluentd/etc/fluentd_multline.conf"
2022-06-20 12:41:58 +0000 [info]: fluent/log.rb:330:info: gem 'fluentd' version '1.14.3'
2022-06-20 12:41:58 +0000 [warn]: fluent/log.rb:351:warn: define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2022-06-20 12:41:58 +0000 [info]: fluent/log.rb:330:info: using configuration file: <ROOT>
  <source>
    @type tail
    path "/fluentd/logs/*.log"
    pos_file "/fluentd/logs/test.log.pos"
    tag "test.logs"
    read_from_head true
    <parse>
      @type "multiline"
      format_firstline "/\\d{4}-\\d{1,2}-\\d{1,2}/"
      format1 /^(?<timestamp>[^ ]* [^ ]*) (?<level>[^\s]+) (?<pid>[^s+]+) \[TID:(?<tid>[,a-z0-9A-Z./]+)\] --- \[(?<thread>.*)\] (?<message>[\s\S]*)/
      unmatched_lines 
    </parse>
  </source>
  <match **>
    @type stdout
  </match>
</ROOT>
2022-06-20 12:41:58 +0000 [info]: fluent/log.rb:330:info: starting fluentd-1.14.3 pid=9 ruby="2.7.5"
2022-06-20 12:41:58 +0000 [info]: fluent/log.rb:330:info: spawn command to main:  cmdline=["/usr/bin/ruby", "-Eascii-8bit:ascii-8bit", "/usr/bin/fluentd", "-c", "/fluentd/etc/fluentd_multline.conf", "-v", "--plugin", "/fluentd/plugins", "--under-supervisor"]
2022-06-20 12:41:59 +0000 [info]: fluent/log.rb:330:info: adding match pattern="**" type="stdout"
2022-06-20 12:41:59 +0000 [info]: fluent/log.rb:330:info: adding source type="tail"
2022-06-20 12:41:59 +0000 [warn]: #0 fluent/log.rb:351:warn: define <match fluent.**> to capture fluentd logs in top level is deprecated. Use <label @FLUENT_LOG> instead
2022-06-20 12:41:59 +0000 [info]: #0 fluent/log.rb:330:info: starting fluentd worker pid=18 ppid=9 worker=0
2022-06-20 12:41:59 +0000 [debug]: #0 fluent/log.rb:309:debug: tailing paths: target = /fluentd/logs/test.log | existing = 
2022-06-20 12:41:59 +0000 [info]: #0 fluent/log.rb:330:info: following tail of /fluentd/logs/test.log
2022-06-20 12:41:59.201105512 +0000 test.logs: {"timestamp":"2022-06-20 19:32:07.264","level":"DEBUG","pid":"7","tid":"bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125","thread":"   scheduling-4","message":"o.s.d.redis.core.RedisConnectionUtils    : Closing Redis Connection."}
2022-06-20 12:41:59.201140475 +0000 test.logs: {"timestamp":"2022-06-20 19:32:07.264","level":"DEBUG","pid":"7","tid":"bb0e9b6d1d704755a93ea1529265bb99.68.16557246000000125","thread":"   scheduling-4","message":"io.lettuce.core.RedisChannelHandler      : dispatching command AsyncCommand [type=DEL, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]"}
2022-06-20 12:41:59.201213082 +0000 test.logs: {"timestamp":"2022-06-20 17:28:27.871","level":"DEBUG","pid":"6","tid":"N/A","thread":"           main","message":"o.h.l.p.build.spi.LoadPlanTreePrinter    : LoadPlan(entity=com.xxxx.entity.ScheduledLeadsInvalid)\n    - Returns\n       - EntityReturnImpl(entity=com.xxxx.entity.ScheduledLeadsInvalid, querySpaceUid=<gen:0>, path=com.xxxx.entity.ScheduledLeadsInvalid)\n    - QuerySpaces\n       - EntityQuerySpaceImpl(uid=<gen:0>, entity=com.xxxx.entity.ScheduledLeadsInvalid)\n          - SQL table alias mapping - scheduledl0_\n          - alias suffix - 0_\n          - suffixed key columns - {id1_51_0_}"}
2022-06-20 12:41:59 +0000 [info]: #0 fluent/log.rb:330:info: fluentd worker is now running worker=0
2022-06-20 12:41:59.199950788 +0000 fluent.info: {"pid":18,"ppid":9,"worker":0,"message":"starting fluentd worker pid=18 ppid=9 worker=0"}
2022-06-20 12:41:59.200662918 +0000 fluent.debug: {"message":"tailing paths: target = /fluentd/logs/test.log | existing = "}
2022-06-20 12:41:59.200844577 +0000 fluent.info: {"message":"following tail of /fluentd/logs/test.log"}
2022-06-20 12:41:59.201480874 +0000 fluent.info: {"worker":0,"message":"fluentd worker is now running worker=0"}

可以看到现在获取到的日志就正常了,前面的多行日志也按我们的预期解析成一行日志了:

{"timestamp":"2022-06-20 17:28:27.871","level":"DEBUG","pid":"6","tid":"N/A","thread":"           main","message":"o.h.l.p.build.spi.LoadPlanTreePrinter    : LoadPlan(entity=com.xxxx.entity.ScheduledLeadsInvalid)\n    - Returns\n       - EntityReturnImpl(entity=com.xxxx.entity.ScheduledLeadsInvalid, querySpaceUid=<gen:0>, path=com.xxxx.entity.ScheduledLeadsInvalid)\n    - QuerySpaces\n       - EntityQuerySpaceImpl(uid=<gen:0>, entity=com.xxxx.entity.ScheduledLeadsInvalid)\n          - SQL table alias mapping - scheduledl0_\n          - alias suffix - 0_\n          - suffixed key columns - {id1_51_0_}"}

当然这整个过程并不复杂,唯一麻烦的地方需要我们去「编写正则表达式」去匹配日志,这可能才是难倒大部分人的一个问题吧

标签:解析器,Fluentd,12,06,fluentd,0000,multiline,2022,20
来源: https://www.cnblogs.com/sanduzxcvbnm/p/16408205.html

本站声明: 1. iCode9 技术分享网(下文简称本站)提供的所有内容,仅供技术学习、探讨和分享;
2. 关于本站的所有留言、评论、转载及引用,纯属内容发起人的个人观点,与本站观点和立场无关;
3. 关于本站的所有言论和文字,纯属内容发起人的个人观点,与本站观点和立场无关;
4. 本站文章均是网友提供,不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属;如您发现该文章侵犯了您的权益,可联系我们第一时间进行删除;
5. 本站为非盈利性的个人网站,所有内容不会用来进行牟利,也不会利用任何形式的广告来间接获益,纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。

专注分享技术,共同学习,共同进步。侵权联系[81616952@qq.com]

Copyright (C)ICode9.com, All Rights Reserved.

ICode9版权所有