日志系统EFK后续: 监控线上日志

在前一篇文章日志系统EFK后续: monitor告警监控中, 我们基本完成了对efk监控告警系统的搭建以及测试, 接下来将日志源切换到线上日志时却出现了大问题, fluentd的CPU使用率高居不下, 且kafka中的告警消息增长速度及其快, 瞬间几十万条, 在我们尝试将线上日志级别调整至INFO以后问题并未缓解, 同时钉钉告警信息一致在刷屏.

fluent-bit不支持tail尾读取, 而我们的日志是保存30天的(后续考虑保留7天, 剩余的压缩), 刚开始的读取量确实很大, 而且之前也发生过fluent-bit偏移量丢失的问题, 所以决定采用fluentd做日志的采集与转发.

fluentd采集器

首先升级fluentd到1.6版本, 修改对应的配置文件

1.fluentd:v1.6

FROM fluent/fluentd:v1.6-debian-1
#FROM fluent/fluentd:v1.2
#增加es插件, kafka插件
USER root
RUN  fluent-gem install fluent-plugin-elasticsearch
RUN  fluent-gem install fluent-plugin-kafka
RUN  fluent-gem install fluent-plugin-rewrite-tag-filter
CMD exec fluentd -c /fluentd/etc/${FLUENTD_CONF} -p /fluentd/plugins $FLUENTD_OPT

2.fluentd.conf

<system>
  log_level error
</system>

# tail采集日志 并解析
<source>
  @type tail
  path  "#{ENV['tailInputPath']}"
  exclude_path  "#{ENV['tailExcludePath']}"
  pos_file "#{ENV['tailPosFile']}"
  tag  fb.dapeng
  path_key  tailKey
  #refresh_interval 5s
  read_from_head  true
  multiline_flush_interval 10s
  <parse>
    @type multiline
    format_firstline /^\d{2}-\d{2} \d{2}:\d{2}:\d{2} \d{3}/
    format1 /^(?<logtime>^\d{2}-\d{2} \d{2}:\d{2}:\d{2} \d{3}) (?<threadPool>[^ ]+|Check idle connection Thread) (?<level>[^ ]+) \[(?<sessionTid>\w*)\] - (?<message>.*)/
  </parse>
</source>

<filter fb.dapeng>
  @type record_transformer
  enable_ruby
  <record>
    hostname 生产
    tag ${record["tailKey"].split('/')[3]}
  </record>
  remove_keys tailKey
</filter>
<filter fb.dapeng>
  @type grep
  <regexp>
    key level
    pattern /^\w+$/
  </regexp>
</filter>
<filter error.fb.dapeng>
    @type grep
    <regexp>
        key sessionTid
        pattern /^[0-9a-f]{16}$/
    </regexp>
</filter>
<match fb.dapeng>
  @type copy
  <store>
    @type kafka2
    brokers "#{ENV['kafkaHost']}:9092"
    topic_key efk
    default_topic efk
    <buffer efk>
        flush_interval 5s
    </buffer>
    <format>
        @type json
    </format>
    compression_codec gzip
    required_acks -1
    max_send_retries 3
  </store>
  <store>
    @type rewrite_tag_filter
    <rule>
      key     level
      pattern /^ERROR$/
      tag     error.fb.dapeng
    </rule>
  </store>
</match>

<match error.fb.dapeng>
    @type kafka2
    brokers "#{ENV['kafkaHost']}:9092"
    topic_key efk_error
    default_topic efk_error
    <buffer efk_error>
        flush_interval 5s
    </buffer>
    <format>
        @type json
    </format>
    compression_codec gzip
    required_acks -1
    max_send_retries 3
</match>
<source>
  @type kafka_group
  brokers "#{ENV['kafkaHost']}:9092"
  consumer_group efk_consumer
  topics efk
  format json
  start_from_beginning false
  max_wait_time 5
  max_bytes 1500000
</source>

# kafka_group 中消息的topic 就是 对应event的tag
<match efk>
    @type elasticsearch
    hosts "#{ENV['esHost']}:9092"
    index_name dapeng_log_index
    type_name  dapeng_log
    #content_type application/x-ndjson
    buffer_type file
    buffer_path /tmp/buffer_file
    buffer_chunk_limit 10m
    buffer_queue_limit 512
    flush_mode interval
    flush_interval 5s
    request_timeout 5s
    flush_thread_count 2
    reload_on_failure true
    resurrect_after 30s
    reconnect_on_error true
    with_transporter_log true
    logstash_format true
    logstash_prefix dapeng_log_index
    template_name dapeng_log_index
    template_file  /fluentd/etc/template.json
    num_threads 2
    utc_index  false
</match>

3.dc-all.yml环境变量配置

      - tailInputPath=/var/logs/*/*.%Y-%m-%d.log
      - tailExcludePath=["/var/logs/*/fluent*.log","/var/logs/*/console.log","/var/logs/*/gc*.log"]
      - tailPosFile=/fluentd/etc/logs.pos
      - kafkaHost=kafka服务器IP
      - esHost=es服务器IP

fluentd 1.4之后支持 "#{ENV['env_key']}" 获取环境变量 env_key 的值

这里我们选用fluentd的tail输入, 监控文件使用strftime, *.%Y-%m-%d.log 只监控当天的日志.
这样就可以使用 read_from_head 从头开始读取, 并且不用担心读取量过大, 同时也不用担心tail尾读取导致日志切换时, 监控列表存在刷新周期 refresh_interval 还未更新时, 导致日志文件开始的一部分日志丢失.

rsync同步文件的坑

切换fluentd采集日志后, kafka消息量降了, 但还是不够, 且告警消息还是重复刷屏, 通过观察发现其中的告警存在重复数据. 也就是说fluentd采集到了重复的日志, 因为我们是通过rsync将线上环境的日志定时同步到efk所在的环境, 这时候就怀疑rsync是不是每次同步都是全部复制, 虽然文件名没有变动, 但fluentd可能在每次同步之后都去从头开始读取, 导致重复日志出现?

首先 tail -f 监听对应日志文件, 发现 rsync 同步之后监听文件并没有改动, 关掉重新监听后发现文件确实有改动, 同时查看kafka中的消息数量, 发现每次同步文件之后, efk_error的offset都会增加相同数量, 这就解释了钉钉告警消息为什么每次都是重复那几条告警了, 这时候基本就确定了是 rsync 的问题导致fluentd在每次同步之后都会从头开始采集.

通过查询 rsync 文档