日志收集Agent，阴暗潮湿的地底世界

本文介绍作者在参与严选技术工作组的日志平台项目时&＃xff0c;在日志收集Agent这块遇到的一些问题&＃xff0c;深入到每个底层细节和大家谈谈。

日志Agent对于使用日志平台的用户来说&＃xff0c;是一个黑盒。对于用户来说&＃xff0c;Agent有些不好的地方&＃xff1a;

• Agent私底下偷偷摸摸都做了些什么事情呢&＃xff1f;&＃xff08;阴暗的&＃xff09;

• Agent的设计实现其实有一些dirty、creepy的地方&＃xff08;潮湿的&＃xff09;

所以我觉得日志收集Agent对大家来说是一个阴暗潮湿的地底世界&＃xff0c;就让我举起火把&＃xff0c;照亮所有dark、dirty、creepy的地方。

背景提要

日志收集我们知道是在宿主服务器通过一个Agent来收集日志数据&＃xff0c;并且将收集到的数据源源不断的发送到日志平台的下游链路消费。

正是因为日志收集Agent是整个日志平台的唯一数据来源&＃xff0c;所以日志收集的地位非常重要。一旦日志收集Agent出现问题&＃xff0c;轻则影响后续链路的报警和查询&＃xff0c;重则影响宿主服务器&＃xff0c;反客为主&＃xff0c;影响更为重要的应用系统。

所以&＃xff0c;先来看看我们选型Agent的时候有些什么阴暗的地方。

日志收集Agent方案

由于日志收集Agent的特殊性&＃xff0c;我们对于Agent的要求优先级由高到低如下:

低耗>稳定>高效>轻量

以此原则&＃xff0c;我们逐步推动Agent的演进。

日志收集Agent初期方案

其实日志平台一开始并没有对比太多其他的Agent方案&＃xff0c;直接就是使用的Flume作为Agent。

why&＃xff1f;

基于MVP&＃xff08;minimum viable product&＃xff09;原则&＃xff0c;日志平台第一版的选项更看重能快速上线、快速试错、快速验证。而且严选这边其实之前就存在一套日志收集系统是用的Flume&＃xff0c;我们决定先复用Flume&＃xff0c;再对其定制。然后其实还有一个更重要的原因&＃xff1a;为了兼容一些历史问题&＃xff08;例如收集的日志要写到北京Kafka的情况&＃xff09;&＃xff0c;我一开始不得不沿用Flume作为Agent的方案。

then&＃xff1f;

以为我们Agent就此受困于历史的漩涡中束手束脚&＃xff0c;止步不前&＃xff1f;不存在的&＃xff0c;我们同步调研了Filebeat的方案。来看看我们对Filebeat的调研工作。

Filebeat作为日志收集Agent

先来看下2者之间的对比&＃xff1a;

权衡优劣后&＃xff0c;我更倾向于选择Filebeat作为日志收集的Agent&＃xff0c;原因如下&＃xff1a;

• 我们对于Agent的需求是低耗、稳定、高效、轻量。扩展性显得并不那么重要&＃xff0c;功能丰富与稳定性&＃xff0c;我更倾向于后者

• 对于输入源&＃xff0c;我们的场景也正好只是基于文件的日志数据收集&＃xff0c;Filebeat已经满足我们的需求场景

• 对于输出源&＃xff0c;Filebeat需要定制开发&＃xff0c;支持http/grpc&＃xff0c;有一定开发成本&＃xff0c;但是完全可以接受

• 目前flume-agent的方案&＃xff0c;日志切分是在flink任务中&＃xff0c;导致后续架构链路冗长。使用Filebeat完全可以把切分的工作放在Agent端来简化架构链路&＃xff0c;这对于后续日志平台的运维也大有裨益

同时&＃xff0c;我们做了Filebeat的压测&＃xff0c;压测数据如下&＃xff1a;

其结果让我们震惊&＃xff0c;在内存占用很低的情况下&＃xff08;3%以下&＃xff09;&＃xff0c;最高CPU占用只有70%&＃xff0c;Flume&＃xff08;平均145%&＃xff09;的一半不到。这使我们以后的Agent方案逐渐向Filebeat倾斜。

好了&＃xff0c;是时候来点干货了&＃xff0c;我们来看看日志收集都有哪些问题&＃xff1f;哪些creepy的设计&＃xff1f;

如何发现日志文件

Agent如何发现哪些日志文件是要被收集的呢&＃xff1f;主要有如下几种方式&＃xff1a;

• 用户配置

• • 优点&＃xff1a;简单高效。用户直接把需要采集的日志文件给配进来&＃xff0c;可以说是最简单高效的办法。

  • 缺点&＃xff1a;日志文件很可能是会按天滚动&＃xff08;rotate&＃xff09;的&＃xff0c;提前配置肯定覆盖不了后面新创建的日志文件。

• 正则匹配&＃xff08;例如&＃xff1a;access_log.\d{4}-\d{2}-\d{2}.\d{2}&＃xff09;

• • 优点&＃xff1a;灵活。能够很好的覆盖到各种滚动新建的日志文件

  • 缺点&＃xff1a;正则由用户输入&＃xff0c;效率堪忧&＃xff0c;一旦发生大量回溯&＃xff0c;很可能CPU 100%。这也是我们最不希望发生在Agent端的问题

• 占位符匹配&＃xff08;例如&＃xff1a;access_log.yyyy-MM-dd.log&＃xff09;

• • 优点&＃xff1a;灵活高效。即能很好的匹配新创建的日志文件&＃xff0c;Agent端的匹配效率也非常高

  • 缺点&＃xff1a;对于一些奇葩命名滚动规则的日志文件不太好适应

日志平台使用的是占位符匹配的方式&＃xff0c;但是后端其实是兼容正则匹配的&＃xff0c;这是出于兼容历史的原因&＃xff0c;后面将逐步去掉正则的匹配的方式。

解决了如何发现文件后&＃xff0c;紧接着就会遇到另一个问题&＃xff1a;

如何发现新创建的文件

直觉做法肯定是轮询目录中的日志文件&＃xff0c;显然这不是个完美的方案。因为轮询的周期太长会导致不够实时&＃xff0c;太短又会耗CPU。

这真是一个艰难的trade-off

我们来对比下Flume&＃xff08;以下所说的Flume都是我们基于Flume改造定制的yanxuan-flume&＃xff09;和Filebeat的做法&＃xff1a;

yanxuan-flume&＃xff1a;轮询

Flume目前是每隔500ms去轮询查找是否有新的日志文件&＃xff0c;基本上就我们前面提到的”直觉做法”。实现简单&＃xff0c;但是我们很难衡量这个500ms是否是一个合适合理的值。

Filebeat&＃xff1a;OS内核指令&＃43;轮询

Filebeat的方案就完善优雅很多。依赖OS内核提供的高效指令&＃xff0c;分别是&＃xff1a;

• Linux&＃xff1a;inotify

• macOS&＃xff1a;fsevents

• Windows&＃xff1a;ReadDirectoryChangesW

来通知是否有新文件&＃xff0c;并且辅助一个周期相对较长的轮询来避免内核指令的bug&＃xff08;具体参考其man page&＃xff09;&＃xff0c;取长补短&＃xff0c;低耗与高效兼得

又多了一个使用Filebeat的理由&＃xff01;

好了&＃xff0c;现在我们已经清楚如何发现文件了&＃xff0c;那么问题又来了&＃xff0c;我们如何知道这个文件是否已经收集过了&＃xff1f;如果没有收集完&＃xff0c;应该从什么位置开始接着收集&＃xff1f;

如何标识一个日志文件收集的位置

一般是用一个文件&＃xff08;这里我们称之为点位文件&＃xff09;来记录收集的文件名&＃xff08;包含文件路径&＃xff09;与收集位置&＃xff08;偏移量&＃xff09;的对应关系&＃xff0c;key就是文件名称&＃xff0c;value就是偏移量。记录到文件的好处是&＃xff0c;在机器宕掉后修复&＃xff0c;我们还能从文件中恢复出上次采集的位置来继续收集。

那么&＃xff0c;点位文件存在什么问题呢&＃xff1f;点位文件使用日志文件名称作为key&＃xff0c;但是一个日志文件的名称是有可能被更改的&＃xff0c;当文件被改名后&＃xff0c;由于点位文件中查询不到对应的采集位置&＃xff0c;Agent会认为是一个全新的日志文件而重头重新收集。所以用文件名称不能识别一个文件。那么问题又来了&＃xff1a;

如何识别一个文件

如何识别一个文件&＃xff0c;最简单的就是根据文件路径&＃43;文件名称。但是我们上面说了&＃xff0c;文件很可能被改名。每个文件其实都有个inode属性&＃xff08;可以使用命令stat test.log查看&＃xff09;&＃xff0c;这个inode由OS保证同一个device下inode唯一。所以自然而然的我们就会想到用device&＃43;inode来唯一确定一个文件。然而inode是会重新分配的&＃xff0c;即当我们删除一个文件后&＃xff0c;其inode是会被重复利用&＃xff0c;分配给新创建的文件。

举个常见例子&＃xff1a;假如日志文件配置为保留30天&＃xff0c;那30天以前的日志文件是会被自动删除的。当删除30天前的日志文件&＃xff0c;其inode正好分配给当天新创建的日志文件&＃xff0c;那当天的日志是不会被收集的&＃xff0c;因为在点位文件中记录了其采集偏移量。

我们来看看Flume和Filebeat是怎么做的&＃xff1a;

yanxuan-flume&＃xff1a;device&＃43;inode&＃43;首行内容MD5

• 优点&＃xff1a;无需用户干预&＃xff0c;能保证唯一识别一个文件。

• 缺点&＃xff1a;需要打开文件读取文件内容&＃xff0c;而且首行内容MD5还是太暴力了&＃xff0c;因为首行很可能是一个超长日志&＃xff0c;再加上MD5&＃xff0c;不仅耗CPU&＃xff0c;而且判断效率有点低。

可以考虑读取首行N个字节的内容md5&＃xff0c;但是N到底取多大呢? 越大相同的概率越小&＃xff0c;效率越低。反过来&＃xff0c;N越小重复的概率越大&＃xff0c;效率越高。这又是一个艰难的trade-off啊&＃xff01;

Filebeat&＃xff1a;device&＃43;inode

• 优点&＃xff1a;判断效率高。无需打开文件读取内容即可判断

• 缺点&＃xff1a;可能会误判

Filebeat提供了一个配置选项来决定何时删除点位文件中的记录&＃xff1a;clean_inactive:72h表示清除72h不活跃的文件对应的点位文件中的记录。基本上我们的文件都是每天&＃xff08;24h&＃xff09;滚动&＃xff08;rotated&＃xff09;的&＃xff0c;那前一天的日志文件是不会写入的&＃xff0c;所以设置clean_inactive:72h是合理的。

那为什么不在日志文件被删除后直接删除点位文件中对应的记录呢&＃xff1f;因为假如我们的日志文件在一个共享的存储分区中&＃xff0c;当这个分区消失了一会&＃xff08;接触不良等情况&＃xff09;又重新出现后&＃xff0c;里面的所有日志文件都会重头开始重新收集&＃xff0c;因为他们的收集状态已经从点位文件中删除了。

我觉得这是一个合理的“甩锅”给使用者的配置选项。

解决了如何标识文件&＃xff0c;如何标识采集状态&＃xff0c;那如何判断一个日志文件采集完了呢&＃xff1f;采集到末尾返回EOF的时候就算采集完了&＃xff0c;可是当采集速度大于日志生产速度的时候&＃xff0c;很可能我们采集到末尾返回EOF后&＃xff0c;又有新的内容写入。所以&＃xff0c;问题就变成&＃xff1a;

如何知道文件内容更新

最简单通用的方案就是轮询要采集的文件&＃xff0c;发现文件内容有更新就采集&＃xff0c;采集完成后再触发下一次的轮询&＃xff0c;既简单又通用。

那具体是轮询什么呢&＃xff1f;

• yanxuan-flume&＃xff1a;按照文件的修改时间排序&＃xff0c;轮询文件内容&＃xff0c;尝试收集&＃xff0c;如果返回是EOF则继续下一份文件

• Filebeat&＃xff1a;按照文件的修改时间排序&＃xff0c;轮询文件的stat状态&＃xff0c;修改时间大于点位文件中记录的时间&＃xff0c;则打开文件收集&＃xff0c;返回EOF则继续下一份文件

相比Flume&＃xff0c;Filebeat又做了一个小优化&＃xff0c;每次不会直接就打开文件&＃xff0c;而是先比较文件的修改时间再决定是否打开文件进行收集。

不得不感叹&＃xff0c;魔鬼在细节&＃xff01;低耗和高效如何兼得&＃xff0c;Filebeat处处都是细节

好了&＃xff0c;知道该什么时候收集了&＃xff0c;那我们具体收集的时候会遇到什么问题呢&＃xff1f;

如何收集多行日志

目前的Agent默认都是单行收集的&＃xff0c;即遇到换行符就认为是一条全新的日志。可是很多情况下&＃xff0c;我们的一条日志是多行的&＃xff0c;比如异常堆栈、格式化后的SQL&Json等。

那如何判断那几行是属于同一条日志呢&＃xff1f;

• yanxuan-flume&＃xff1a;Flume原生是不支持的&＃xff0c;我们自己写了个插件&＃xff0c;通过配置一条日志的开头字符S来判断。假如一行日志的开头不是S&＃xff0c;则认为是和上一行属于同一条日志。

• Filebeat&＃xff1a;支持Flume类似的方式&＃xff0c;同时提供了配置项negate&＃xff1a;true 或 false&＃xff1b;默认是false&＃xff0c;匹配开头字符S的行合并到上一行&＃xff1b;true&＃xff0c;不匹配S的行合并到上一行。能够覆盖更多的多行日志场景。

当然还有其他相关配置来兜底合并行可能带来的问题&＃xff0c;例如一次最多合并几行和合并行的超时时间来防止可能的内存溢出与卡死。

万无一失了吗&＃xff1f;想想多行日志的最后一行按照以上的逻辑可以正常收集吗&＃xff1f;例如下图所示&＃xff1a;

如何处理多行日志的最后一行

当多行日志收集遇到最后一行怎么收集呢&＃xff1f;还是来比较下Flume和Filebeat的做法&＃xff1a;

• yanxuan-flume&＃xff1a;遇到EOF即认为是这条多行日志收集完了。这有个问题就是&＃xff0c;很可能这条多行日志还没有写完&＃xff0c;就被收集发送出去了。而且当收集速度大于日志写入速度的时候或者异步打印日志的时候&＃xff0c;又很容易发生这种情况

• Filebeat&＃xff1a;遇到EOF会回退之前读取的内容&＃xff0c;然后一直持有这个文件句柄&＃xff08;直到超时&＃xff09;&＃xff0c;直到新一行日志写入&＃xff0c;根据新一行日志的行首字符匹配来判断是否当前行的日志结束。所以Filebeat的存在的问题是很可能最后一行永远不会被收集

目前业界貌似没有太好的办法来完美解决这个问题。个人觉得基于Filebeat的多行合并的超时时间配置选项能够很大程度缓解这个问题&＃xff0c;因为多行日志往往也是一次性写入的&＃xff0c;超过一定时间写入的往往都是一条全新的日志。

原文链接&＃xff1a;https://zacard.net/2019/06/15/log-agent/

Kubernetes管理员认证&＃xff08;CKA&＃xff09;培训

本次CKA培训在北京开班&＃xff0c;基于最新考纲&＃xff0c;通过线下授课、考题解读、模拟演练等方式&＃xff0c;帮助学员快速掌握Kubernetes的理论知识和专业技能&＃xff0c;并针对考试做特别强化训练&＃xff0c;让学员能从容面对CKA认证考试&＃xff0c;使学员既能掌握Kubernetes相关知识&＃xff0c;又能通过CKA认证考试&＃xff0c;学员可多次参加培训&＃xff0c;直到通过认证。点击下方图片或者阅读原文链接查看详情。