记Filebeat系统资源使用优化

如今企业应用分布式、微服务盛行,针对分布于多节点的日志,会使用分布式日志系统架构,来满足业务开发查询多节点的日志并进行问题排查和定位。迄今为止,最为通用和成熟的就是elastic的ELK架构,我司现在也是按照如下通用架构(本文使用7.2版本的elastic套件):

  • filebeat(本文重点):日志采集器,启动于业务服务器进行日志采集,并发送到kafka指定topic
  • kafka:大规模的企业应用通常会产生大量的日志,kafka可以为增长的日志削峰填谷
  • logstash: 将kafka的日志数据作为input,通过grok、oniguruma、mutate等过滤器将异构数据解析为结构化数据,最终存储到Elasticsearch
  • Elasticsearch:热门开源的搜索引擎,建立在 Apache Lucene 之上,在当前场景用于存储结构化的日志数据
  • kibana:用于检索和管理ES数据的UI界面

本文重点:

本文将着重关注filebeat,在filebeat在生产部署后,必定会对服务CPU、内存、网络有影响,如果将这些因素都在可控范围内,那是完全可以接受的。但是可能由于我们的配置不合理,或者非预期的情况导致CPU、内存占用过大,势必会影响到同在一起的业务应用稳定性。

我们将在本文一步步介绍我们在使用过程中遇到的问题,配置的优化,如何确保filebeat部署在业务主机上对业务的影响降到最低,如何使用cgroup来限制filebeat的系统资源使用配额!

问题场景

有些文章说filebeat的内存消耗很少,不会超过100M,这是没有针对场景和没有经过测试不严谨的说法(刚开始我们也没有完全覆盖所有情况进行测试,当然部分偶然情况有时无法预知),当真正按照默认的简单配置将filebeat部署到生产环境,或者某个参数配置错误,都可能会出现意想不到的问题,轻则影响服务的整体性能,重则可能造成应用被OOM-killer导致业务中断。我们在刚开始使用filebeat时,觉得这个组件已经如此成熟,应该问题不大。所以使用了最简单最基本的配置将其部署,为后来的问题埋下了祸根!

我们在实际使用中的确遇到了如下问题:

  • Filebeat内存爆增至数GB、导致业务服务器触发OOM-killer,将业务进程kill掉
  • 平常不会很频繁,但一旦压测或者有大量异常时就会出现以上问题

来看几个问题样本:

oom.png

这里是filebeat导致Linux OOM 的一个场景,可使用 dmesg -T 查看,这里可以看到,在OOM时,filebeat大概占用523561*4k ~= 2G(rss是内存页数,乘上内存页大小4k就是实际物理内存)(多的时候有过5G,比如有的日志文件中打印了很多二进制内容)

image-20200326002050633

使用业务问题样本日志进行的测试的结果

初版filebeat.yml配置

这是初版的配置文件,相对简单,基本没有做什么特殊的配置:

这是一个错误的样本配置,请不要使用

#=========================== Filebeat inputs =============================
filebeat.inputs:
- type: log
  enabled: true
  paths:                                # 日志文件路径
    - /data/logs/*/*.log
  exclude_files: [.*file3.*|.*file4.*]  # 忽略的文件列表,正则匹配
  fields:                               # 在事件json中添加字段
    appName: ${serviceName}
    agentHost: ${hostIp}
  fields_under_root: true               # 将添加的字段加在JSON的最外层
  tail_files: false                     # 不建议一直开启,从日志文件的最后开始读取新内容
  multiline:                            # 多行匹配日志
    pattern: '\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}' # 匹配一个以 [YYYY-MM-DD HH:mm:ss 开头的行
    negate: true                        # 将 pattern 取否(即不匹配pattern的情况)
    match: after                        # 将其追加到上一行之后 pattern + negate + match 组合成一条语意为: 如果不匹配 [YYYY-MM-DD HH:mm:ss 开头的行,则将其合并到当前行的上一行
    timeout: 30s                        

#=============================== Processors ===============================
# ...此处省略
#=============================== output ===============================
output.kafka:
  enabled: true
  hosts: ['ip1:9092','ip2:9092']
  topic: 'my_topic'
  partition.round_robin:
    reachable_only: true
  worker: 4
  required_acks: 1
  compression: gzip
  max_message_bytes: 1000000            # 10MB
#================================ Logging ======================================
# ...此处省略

初期的问题和调整:

我们接收业务反馈CPU占据到了300%上下(四核),并且偶现开头出现的OOM现象。

经过文档的查阅,发现几个明显的配置问题,并针对其做过一次初步的优化

  1. max_bytes:单行日志的大小,默认为10M
  2. queue.mem.events:内存队列的大小默认为4096,有这个一个公式 max_bytes * queue.mem.events等于约占的内存量,这里默认10M * 4096=40G,再考虑到队列存储已经编码为json的数据,则原始数据应该也会存储在内存中,那满打满算就得有80G内存占用,即使不存储原始日志,日常的服务器也难以接受这40G的内
  3. max_procs:没有限制CPU内核数使用,在日志较频繁时可能导致CPU满载
  4. ignore_older:由于服务器上有历史日志,可以使用此选项忽略较旧的文件

初步调整:

max_procs: 1   # *限制一个CPU核心,避免过多抢占业务资源
filebeat.inputs:
    - type: log
      ignore_older: 48h # 忽略这个时间之前的文件(根据文件改变时间)
      max_bytes: 20480  # *单条日志的大小限制,将其从默认10M降低到20k,按照公式计算 20k * 4096 ~= 80M
        # ... 省略其他配置

问题反复及之后的处理

上面的改动,以为已经控制住问题,但是在不久之后还是反复出现了多次同样的OOM问题

filebeat限制单条消息最大不能超过20k,默认内存队列存储4096条记录,再加上明文日志,最高内存理论最高值在 20k * 4096 * 2 = 160M 左右浮动,即使做了以上限制,还是不时出现内存爆增的情况

一时没有找到问题解决方案,我们做了如下的几个阶段策略:

阶段一:降低非预期情况下对应用的影响

阶段二:重新梳理和优化配置,达到优化内存的目的

阶段一:降低非预期情况下对应用的影响

降低非预期情况下对应用的影响,是将filebeat进程的oom_score_adj值设置为999,在出现意外情况时OOM也优先 kill 掉filebeat,从而达到即使出现意外情况,也不会影响到业务进程

具体的操作是:

启动filebeat -> 获取进程PID -> 写入/proc/$pid/oom_score_adj 为999

OOM killer 机制一般情况下都会kill掉占用内存最大的进程,在kill进程时,有个算分的过程,这个算分过程是一个综合的过程,包括当前进程的占用内存情况,系统打分,还有可由用户控制的oom_score_adj分值,将影响整体算分。

oom_score_adj的取值范围是 -1000 至 1000,值越大,OOM在kill时会优先kill掉此进程,为了最大限度让系统kill掉filebeat,我们必须将此值调整到最大

阶段二:重新梳理和优化配置,达到优化内存的目的

针对多次问题的场景,进行样本的提取,发现多次问题出现的都是在大量的堆栈异常日志中出现,怀疑是多行合逻辑不对导致的问题:

下面我们来着重看一下多行最初配置:

 multiline:                            # 多行匹配日志
    pattern: '\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}' # 匹配一个以 [YYYY-MM-DD HH:mm:ss 开头的行
    negate: true                        # 将 pattern 取否(即不匹配pattern的情况)
    match: after                        # 将其追加到上一行之后 pattern + negate + match 组合成一条语意为: 如果不匹配 [YYYY-MM-DD HH:mm:ss 开头的行,则将其合并到当前行的上一行
    timeout: 30s                        

发现官网对于此参数的默认值是5s,但是现在却被误配置成了30s,肯定是有问题的啦

image-20200326024501744

问题的原因应该就在 multiline.timeout这个参数之上,我们尝试调整多次参数的大小进行测试:

# 由于样本不同,可能内存量也会有所不同,这里选取的是在业务服务中有大量错误堆栈的日志进行测试
# 在其他参数不变的情况下测试
multiline.timeout: 30s ->  10s  ->   3s  ->  2s   ->   1s
                   5.3G -> 4.8G -> ~2.5G -> ~730M  -> ~540M

我的对官方的这句话的理解是:

超时时间后,即使还未匹配到下一个多行事件,也将此次匹配的事件刷出

如果日志中如果包含很多错误堆栈,或者不规范的日志大量匹配多行逻辑,会产生过多的多行合并任务,但是超时时间过长,过多的任务就会最大限度的匹配和在内存中等待,占用更多的内存!

除此以外我们也做了其他调整包括但不限于如下:

queue.mem.events:从默认的4096 设置到了2048

queue.mem.flush.min_events: 从默认2048设置到了1536

multiline.max_lines:从默认500行设置到了200行

最后我们的最优配置如下,在调整之后将问题样本进行测试,内存只占用350M~500M之间:

#=========================== Filebeat inputs =============================
max_procs: 1                            # *限制一个CPU核心,避免过多抢占业务资源
queue.mem.events: 2048                  # 存储于内存队列的事件数,排队发送 (默认4096)
queue.mem.flush.min_events: 1536        # 小于 queue.mem.events ,增加此值可提高吞吐量 (默认值2048)
#queue.mem.flush.timeout: 1s             # 这是一个默认值,到达 min_events 需等待多久刷出
filebeat.inputs:
- type: log
  enabled: true
  ignore_older: 48h                     # 忽略这个时间之前的文件(根据文件改变时间)
  max_bytes: 20480                      # *单条日志的大小限制,建议限制(默认为10M,queue.mem.events * max_bytes 将是占有内存的一部分)
  recursive_glob.enabled: true          # 是否启用glob匹配,可匹配多级路径(最大8级):/A/**/*.log => /A/*.log ~ /A/**/**/**/**/**/**/**/**/*.log  
  paths:                                # 日志文件路径
    - /data/logs/**/*.log
  exclude_files: [.*file1.*|stdout.log|.*file2.*] # 忽略的文件列表,正则匹配
  fields:                               # 在事件json中添加字段
    appName: ${serviceName}
    agentHost: ${hostIp}
  fields_under_root: true               # 将添加的字段加在JSON的最外层
  tail_files: false                     # 不建议一直开启,从日志文件的最后开始读取新内容(保证读取最新文件),但是如果有日志轮转,可能导致文件内容丢失,建议结合 ignore_older 将其设置为false
  multiline:                            # 多行匹配日志 (https://www.elastic.co/guide/en/beats/filebeat/7.2/multiline-examples.html)
    pattern: '\[\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}' # 匹配一个以 [YYYY-MM-DD HH:mm:ss 开头的行
    negate: true                        # 将 pattern 取否(即不匹配pattern的情况)
    match: after                        # 将其追加到上一行之后 pattern + negate + match 组合成一条语意为: 如果不匹配 [YYYY-MM-DD HH:mm:ss 开头的行,则将其合并到当前行的上一行
    max_lines: 200                      # 最多匹配多少行,如果超出最大行数,则丢弃多余的行(默认500)
    timeout: 1s                         # 超时时间后,即使还未匹配到下一个行日志(下一个多行事件),也将此次匹配的事件刷出 (默认5s)

#=============================== Processors ===============================
# 省略
#=============================== output ===============================
output.kafka:
  enabled: true
  hosts: ['ip1:9092','ip2:9092']
  topic: 'my_topic'
  partition.round_robin:
    reachable_only: true
  worker: 4
  required_acks: 1
  compression: gzip
  max_message_bytes: 1000000            # 10MB
#================================ Logging ======================================
# 省略

使用cgroup限制资源用量

对于我们的业务机器来说,让filebeat独占一个CPU去进行日志收集,显然不被业务人员所接受,因为在业务高峰期日志量会很大,filebaat进行大吞吐量的日志收集、多行合并、消息发送;很有可能会限制业务的性能,可能没有filebeat我原本需要10台主机,但是有了filebeat我就需要15台主机来承载高峰业务。

上面的配置虽然已经基本控制住内存用量,但也有可能出现不同的不可预期的情况导致内存增长

我们该如何限制CPU使用量和应对意想不到的内存增长情况?

答案是:绝对性的控制CPU/内存在一个范围内,我们可以使用cgroup来实现

什么是cgroup?

cgroups 是Linux内核提供的一种可以限制单个进程或者多个进程所使用资源的机制,可以对 cpu,内存等资源实现精细化的控制,容器 Docker 技术就使用了 cgroups 提供的资源限制能力来完成cpu,内存等部分的资源控制。

另外,开发者也可以使用cgroup提供的精细化的控制能力,来限制某一组/一个进程的资源使用,比如我们的日志agent需要部署到应用服务器,为了保证系统稳定性,可以限制agent的资源用量在合理范围。

由于篇幅限制,这里对cgroup就不多做介绍了,只说如何使用起来,如果有不明白的,可以查看下方参考链接

如何使用cgroup

cgroup相关的所有操作都是基于内核中的cgroup virtual filesystem,使用cgroup很简单,挂载这个文件系统即可。一般情况默认已经挂载到/sys/fs/cgroup目录下了

mount | grep cgroup 查看系统默认是否挂载cgroup,cgroup包含很多子系统,用来控制进程不同的资源使用,我们只用其中cpu和memory这两个

image-20200326042002337

用到的cgroup的子系统:

  1. cpu 子系统,主要限制进程的 cpu 使用率
  2. memory 子系统,可以限制进程的 memory 使用量

创建子cgroup

  • 如果需要限制cpu,则在已挂载的 /sys/fs/cgroup/cpu 子系统下建立任意目录,如filebeat_cpu
  • 如果需要限制内存,则在已挂载的 /sys/fs/cgroup/memory 子系统下建立任意目录,如filebeat_memory

filebeat_cpu和filebeat_memory下都会自动生成与上级目录相同的文件,我们重点关注一下几个文件

filebeat_cpu
    - cgroup.procs        # 限制的进程pid        
    - cpu.cfs_period_us   # 用来配置时间周期长度  (us)
    - cpu.cfs_quota_us    # 用来配置当前cgroup在设置的周期长度内所能使用的CPU时间数(us)
    
# cpu.cfs_period_us&cpu.cfs_quota_us 两个文件配合起来设置CPU的使用上限
# cfs_period_us的取值范围为1毫秒(ms)到1秒(s),cfs_quota_us的取值大于1ms即可
# 如果cfs_quota_us的值为-1(默认值),表示不受cpu时间的限制
# 如限制使用1个CPU的25%(每40ms能使用10ms的CPU时间,即使用一个CPU核心的25%)
# 则echo 40000 > cpu.cfs_period_us && echo 40000 > cpu.cfs_quota_us

filebeat_memory
    - cgroup.procs            # 限制的进程pid
    - memory.limit_in_bytes   # 限制的内存大小
    - memory.oom_control     

# memory.oom_control
# 0:将启动OOM-killer,当内核无法给进程分配足够的内存时,将会直接kill掉该进程
# 1:表示不启动OOM-killer,当内核无法给进程分配足够的内存时,将会暂停该进程直到有空余的内存之后再继续运行;
# 同时,memory.oom_control还包含一个只读的under_oom字段,用来表示当前是否已经进入oom状态,也即是否有进程被暂停了。

改造我们的filebeat启动脚本,支持在启动后限制内存和cpu:

restartFilebeat.sh

#!/bin/sh
# @metainfo: filebeat 启动脚本
# @author: struy
# 1.设置filebeat需要的主机和应用信息,详情见filebeat.yml
# 2.设置针对filebeat CPU、内存的 cgroup 限额: CPU -> 单核25%,内存 -> 500M 
# 3.停止旧进程,检查环境变量,重启filebeat
# 4.写入filebeat进程oom_score_adj值(999),写入进程号至为filebeat准备的cgroup.procs中
# 5.review 配置信息

source /etc/profile
source ~/.bash_profile

# ==========================variable============================= #
_hostIp=`ifconfig eth0|grep "inet "|awk '{print $2}'`
_serviceName=(`ps -ef |grep -Ev 'grep' | grep -Eo 'applicationName=.*? ' | awk '{print  $1}' | awk -F = '{print $2}'`)

filebeat_oom_score_adj=999              # OOM时,将优先OOM掉filebeat,虽然现在占用不大,为避免特殊情况影响业务
filebeat_memory_limit_mb=500M     # 内存限额
filebeat_single_cpu_scale=0.25      # 占单个cpu的比例
filebeat_cfs_period_us=40000            # CPU的时间周期
filebeat_cfs_quota_us=`echo $filebeat_single_cpu_scale $filebeat_cfs_period_us | awk '{printf "%0.0f\n" ,$1*$2}'`           # 周期内的限额 

# ========================== ENV ============================= #
export hostIp=$_hostIp
export serviceName=$_serviceName

# ========================== cgroup check and setting ============================= #
if [[ -d "/sys/fs/cgroup/cpu/filebeat_cpu" ]] && [[ -d "/sys/fs/cgroup/memory/filebeat_memory" ]];then
    echo 'cgroup [filebeat_cpu、filebeat_memory] is exist'
else
    echo 'cgroup [filebeat_cpu、filebeat_memory] is not exist , now mkdir and setting quota'
    # CPU
    mkdir /sys/fs/cgroup/cpu/filebeat_cpu
    # 内存
    mkdir /sys/fs/cgroup/memory/filebeat_memory
fi

# cfs_period_us用来配置时间周期长度
# cfs_quota_us用来配置当前cgroup在设置的周期长度内所能使用的CPU时间数
# 两个文件配合起来设置CPU的使用上限。两个文件的单位都是微秒(us),
# cfs_period_us的取值范围为1毫秒(ms)到1秒(s),cfs_quota_us的取值大于1ms即可
# 如果cfs_quota_us的值为-1(默认值),表示不受cpu时间的限制
# 限制使用1个CPU的25%(每40ms能使用10ms的CPU时间,即使用一个CPU核心的25%)
echo $filebeat_cfs_period_us > /sys/fs/cgroup/cpu/filebeat_cpu/cpu.cfs_period_us
echo $filebeat_cfs_quota_us > /sys/fs/cgroup/cpu/filebeat_cpu/cpu.cfs_quota_us

# 内存限制小于 400M,写入自动转换为bytes
echo $filebeat_memory_limit_mb > /sys/fs/cgroup/memory/filebeat_memory/memory.limit_in_bytes
# 0:即使系统有交换空间,也不使用交换空间
#echo 0 > /sys/fs/cgroup/memory/filebeat_memory/memory.swappiness
# 0:OOM-killer 1:暂停进程等有可用内存再继续运行
#echo 0 > /sys/fs/cgroup/memory/filebeat_memory/memory.oom_control


# ==========================kill old============================= #
oldPid=(`ps -ef|grep 'agent7.2/filebeat-7.2.0-linux-x86_64/filebeat' |grep -v 'grep'|awk '{print $2}'`)
if [[ ! $oldPid ]]; then
    echo "filebeat agent not runing,now run!"
else
    echo "oldPid => [${oldPid[*]}],kill now"
    kill ${oldPid[*]}
fi

sleep 1s

# ========================== check ENV and run ============================= #
if [[ ! $hostIp ]]||[[ ! $serviceName ]]; then
  echo "env [hostIp] or [serviceName] is not set, cancel start!"
else
  if [ ${#serviceName[*]} -ne 1 ]; then
   echo "env [serviceName] more than one:serviceName => [${serviceName[*]}],cancel start!"
  else
   nohup /data/agent7.2/filebeat-7.2.0-linux-x86_64/filebeat run -e -c /data/agent7.2/filebeat-7.2.0-linux-x86_64/filebeat.yml  >> /data/agent7.2/nohup.out 2>&1 &
  fi
fi

# !!! 确保已经在运行,延时可能在cgroup未生效的情况下应用内存就增长了,但是不会超过限制内存的20%
sleep 1s

pid=(`ps -ef|grep 'agent7.2/filebeat-7.2.0-linux-x86_64/filebeat' |grep -v 'grep'|awk '{print $2}'`)


if [[ ! $pid ]];then
    echo "filebeat not runing,cgroup no check"
else
    # ========================== setting oom_socre_adj ============================= #
    echo $filebeat_oom_score_adj > /proc/$pid/oom_score_adj
    # ========================== setting filebeat cgroup procs ============================= #
    echo $pid > /sys/fs/cgroup/cpu/filebeat_cpu/cgroup.procs
    echo $pid > /sys/fs/cgroup/memory/filebeat_memory/cgroup.procs
fi

# ========================== review setting ============================= #
echo "pid->$pid hostName->$HOSTNAME hostIp->$hostIp appName->$serviceName" \
"filebeat_oom_score_adj->"`cat /proc/$pid/oom_score` \
"filebeat_cpu/cpu.cfs_period_us->"`cat /sys/fs/cgroup/cpu/filebeat_cpu/cpu.cfs_period_us` \
"filebeat_cpu/cpu.cfs_quota_us->"`cat /sys/fs/cgroup/cpu/filebeat_cpu/cpu.cfs_quota_us` \
"filebeat_memory/memory.limit_in_bytes->"`cat /sys/fs/cgroup/memory/filebeat_memory/memory.limit_in_bytes`

限制:

CPU -> 单核25%

内存 -> 500M,大于此值则触发cgroup的OOM-killer机制

优化前优化后的对比

优化前:

image-20200326050828639

优化后:

企业微信截图_272f085f-05d7-4342-bf10-311f0ebdb805

参考

推荐阅读更多精彩内容