filebeat重复采集数据问题排查

一.背景

公司基于ELK的日志系统一直很稳定,不过有一天下午,微信收到Kafka topic延迟堆积告警将近6000w条数据。首先接收到告警,查看了这个业务最近7天的一个流量图,基本上量都很小,每秒也就2k左右的数据流量,
但是今天下午流量直接跑到了30k/s并且持续了一段时间.

首先找到业务方负责的SRE同事,确认流量是否属于正常(不排除上线新款游戏流量暴增的情况).SRE同事确认流量异常,最近无新游戏或者活动上线,开始排查原因。我们看到的现象是,某台服务器日志文件路径应该是今天只采集0702.log, 但是今天却把06月份-0702的日志全部又重复采集了一遍。SRE同事那边负责排查最近变更情况,我负责查看filebeat log, 排查是否是因为filebeat某些bug或者使用不当导致.

二.排查过程

第一天排查这个事情双方排查都无进展, 我查看了filebeat log没发现任何不对劲的地方,filebeat首先没重启,log也没发现一些关键性的错误log或者重复采集的一些记录。就此,当天排查到晚上还是无结果,只能第二天继续排查。 SRE同事那边也是没有什么收获.

第二天,正在排查昨天这个问题的时候。突然,有一个业务的流量也是异常暴增,现象与昨天一致,不过不是昨天的业务,是另外一个业务的单台机器导致的(查看ES index里面的host来定位重复采集log的主机)。 这个使得我们更加重视了这个情况,必须要解决这个问题,因为已经两次出现了.

终于到下午,SRE同事说他可能发现了造成这2次故障根本原因。我也是百思不得其解,比较激动想知道什么原因, 因为我这边查看filebeat log都没任何进展,没有异常出现,查了很多资料,别人遇到的filebeat重复采集和我们的情况也不一致, 最后就差查看filebeat源码了。。。 十分激动,到底是什么原因。

原因是这样: 昨天他们在扩容业务服务器,原服务器A是被克隆的机器,克隆出了新的机器A1。但是就是这个变更,有一个地方他没注意,克隆好的A1和A一模一样(连hostname都没改),并且服务器默认有一个脚本检测自动拉起filebeat,虽然filebeat data目录已经记录了采集log 的offset, 但是这个只是在A服务器上生效,因为这些文件的inode与采集的log文件路径是一一对应的。不过到了A1机器情况截然不同, filebeat data里面记录的文件路径虽然和A是一样的,但是文件的inode已经发生了变化. filebeat是依赖与inode来对采集文件进行记录offset的,所以A1重复将所有的log文件采集了一遍. 但是为什么我们没发现是这个原因呢? 因为A1被克隆出来的时候, hostname和A一模一样,我们通过ES INDEX里面host的记录排查, 导致我们一去取排查A服务器….., 其实都是A1在传输log。 早上再次出现的情况也是克隆机器导致的,克隆启动服务器的时间点和流量暴增时间点完全吻合。

三.事后总结

我们当时就在群里反馈过,确认一下最近是否做了某些变更? 因为之前其他业务线也在使用filebeat一两年了没出现过这种情况。 但是业务方同事坚持认定没做变更…..,比较蛋疼

后面我们就要汲取教训了, SRE在克隆机器的时候:

1.首先hostname必须要改,否则排查问题具备迷惑性

2.对于这种filebeat采集或者开机自启的进程要了解,克隆新机器以后,看是否需要自启动还是手动启动,确认好之后再克隆