首页 > 代码库 > 基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程
版权声明:本文由王亮原创文章,转载请注明出处:
文章原文链接:https://www.qcloud.com/community/article/214
来源:腾云阁 https://www.qcloud.com/community
现象
长期运营中发现部署了flume集群的磁盘满,经过排查发现flume的日志目录导致。
具体问题
具体看flume的大文件日志发现,某个MySQL相关的sink持续抛出异常,打印了大量的日志
分析过程
根据这个异常信息(exception)即:com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after statement closed
字面意思为MySQL服务的状态(连接)已经关闭的状态下,仍然有提交事务操作,抛出了异常,但这个异常持续抛出,仍需要深入分析。
配置分析
既然是flume抛出的,且与MySQL有关,那缩小问题范围,查找flume里谁在写MySQL。(flume的配置一般位于/etc/flume/conf/agent/flume.conf)
根据配置中唯一一条与MySQL相关的配置逻辑:读取HiveServer的日志,过滤其中的SQL语句(以Metadata collec*过滤),结果存入到sink里配置的MySQL数据表hive_run_sqlinfo。
flumeagent逻辑分析
以上sink里调用了一个com.tencent.tbds.flume.sink.MysqlSinkForMetadata的类,这是一个自定义类,我们在引用路径里找到这个类所在jar并反编译之(decompiler),基本逻辑与注释如下:
Sink初始化阶段
Sink循环执行阶段
Sink关闭阶段
关闭阶段仅仅检查连接是否存在。
可能的原因
从sink的逻辑看,只有在空连接的情况下,sink状态才会是BACKOFF,其他情况下状态都是READY,且在向MySQL提交事务前后,不会检查连接状态,即使在SQL抛出异常的情况下也没有修改sink状态,导致提交抛出异常后,sink循环执行,循环抛出异常。这里就是不断抛出异常的根本。那么连接到底是什么时候关闭的呢?这里的原因猜测有2个:(1)sink长时间与MySQL没有交互,超过连接自动关闭时间;(2)MySQL的异常关闭。
问题确认
是否sink长时间与MySQL无交互
查询MySQL的超时配置如下:
配置为默认配置28800秒即8小时。
查看HiveServer的日志,统计每小时执行SQL的数量如下:
可见,sink与MySQL之间的断开并非二者长期无交互。
是否人为断开服务
查询人为启动MySQL的时间如下:
flume的异常时间如下:(从异常提交的事务本身内容的时间看):
时间吻合。
结论
MySQL服务异常导致flume提交事务时连接中断,且flume没有处理这种异常,引发死循环提交事务,并在这种异常情况下,flume已无法正常工作。
问题重现
根据以上的推论,可进行如下验证这个异常:
HiveServer产生日志
在HUE里执行多次HiveSQL
手动强制关闭MySQL
手动重启flume写入的MySQL实例。
查看flume表现
flume进入无限循环的抛出异常状态,验证成功。
总结
这里的主要原因是MySQL服务异常导致产生的连锁反应。权宜之计可以在sink的代码中提交事务出异常时,修改下sink的状态为BACK.OFF,防止不断打印日志造成机器磁盘满影响其他服务(待验证)。
基于TBDS的flume异常问题排查过程