如今企业应用分布式、微服务盛行,针对分布于多节点的日志,会使用分布式日志系统架构,来满足业务开发查询多节点的日志并进行问题排查和定位。迄今为止,最为通用和成熟的就是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掉
- 平常不会很频繁,但一旦压测或者有大量异常时就会出现以上问题
来看几个问题样本:
这里是filebeat导致Linux OOM 的一个场景,可使用
dmesg -T
查看,这里可以看到,在OOM时,filebeat大概占用523561*4k ~= 2G(rss是内存页数,乘上内存页大小4k就是实际物理内存)(多的时候有过5G,比如有的日志文件中打印了很多二进制内容)
使用业务问题样本日志进行的测试的结果
初版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现象。
经过文档的查阅,发现几个明显的配置问题,并针对其做过一次初步的优化
-
max_bytes
:单行日志的大小,默认为10M -
queue.mem.events
:内存队列的大小默认为4096,有这个一个公式max_bytes * queue.mem.events
等于约占的内存量,这里默认10M * 4096=40G
,再考虑到队列存储已经编码为json的数据,则原始数据应该也会存储在内存中,那满打满算就得有80G内存占用,即使不存储原始日志,日常的服务器也难以接受这40G的内 -
max_procs
:没有限制CPU内核数使用,在日志较频繁时可能导致CPU满载 -
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,肯定是有问题的啦
问题的原因应该就在 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这两个
用到的cgroup的子系统:
- cpu 子系统,主要限制进程的 cpu 使用率
- 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机制
优化前优化后的对比
优化前:
优化后: