基于TBDS的flume异常问题排查过程

版权声明:本文由王亮原创文章,转载请注明出处: 
文章原文链接:https://www.qcloud.com/community/article/214

来源:腾云阁 https://www.qcloud.com/community

现象

长期运营中发现部署了flume集群的磁盘满,经过排查发现flume的日志目录导致。

具体问题

具体看flume的大文件日志发现,某个MySQL相关的sink持续抛出异常,打印了大量的日志
基于TBDS的flume异常问题排查过程

分析过程

根据这个异常信息(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)
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程

根据配置中唯一一条与MySQL相关的配置逻辑:读取HiveServer的日志,过滤其中的SQL语句(以Metadata collec*过滤),结果存入到sink里配置的MySQL数据表hive_run_sqlinfo。

flumeagent逻辑分析

以上sink里调用了一个com.tencent.tbds.flume.sink.MysqlSinkForMetadata的类,这是一个自定义类,我们在引用路径里找到这个类所在jar并反编译之(decompiler),基本逻辑与注释如下:

Sink初始化阶段
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程

Sink循环执行阶段
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程
基于TBDS的flume异常问题排查过程

Sink关闭阶段
基于TBDS的flume异常问题排查过程
关闭阶段仅仅检查连接是否存在。

可能的原因

从sink的逻辑看,只有在空连接的情况下,sink状态才会是BACKOFF,其他情况下状态都是READY,且在向MySQL提交事务前后,不会检查连接状态,即使在SQL抛出异常的情况下也没有修改sink状态,导致提交抛出异常后,sink循环执行,循环抛出异常。这里就是不断抛出异常的根本。那么连接到底是什么时候关闭的呢?这里的原因猜测有2个:(1)sink长时间与MySQL没有交互,超过连接自动关闭时间;(2)MySQL的异常关闭。

问题确认

是否sink长时间与MySQL无交互
查询MySQL的超时配置如下:
基于TBDS的flume异常问题排查过程
配置为默认配置28800秒即8小时。
查看HiveServer的日志,统计每小时执行SQL的数量如下:
基于TBDS的flume异常问题排查过程
可见,sink与MySQL之间的断开并非二者长期无交互。

是否人为断开服务
查询人为启动MySQL的时间如下:
基于TBDS的flume异常问题排查过程
flume的异常时间如下:(从异常提交的事务本身内容的时间看):
基于TBDS的flume异常问题排查过程
时间吻合。

结论
MySQL服务异常导致flume提交事务时连接中断,且flume没有处理这种异常,引发死循环提交事务,并在这种异常情况下,flume已无法正常工作。

问题重现

根据以上的推论,可进行如下验证这个异常:

HiveServer产生日志

在HUE里执行多次HiveSQL
基于TBDS的flume异常问题排查过程

手动强制关闭MySQL

基于TBDS的flume异常问题排查过程
手动重启flume写入的MySQL实例。

查看flume表现

基于TBDS的flume异常问题排查过程
flume进入无限循环的抛出异常状态,验证成功。

总结

这里的主要原因是MySQL服务异常导致产生的连锁反应。权宜之计可以在sink的代码中提交事务出异常时,修改下sink的状态为BACK.OFF,防止不断打印日志造成机器磁盘满影响其他服务(待验证)。

上一篇:nvGRAPH三角形计数和遍历示例


下一篇:json&pickle&shelve模块