穿越迷雾:一次多组件超时的 Flink 崩溃定位小记

2021-09-29 20:43:26 浏览数 (2)

问题现象

上周四下午,告警系统突然提示某位大客户的作业频繁发生崩溃和重启,现象是作业运行起来 2 分钟左右,JobManager 就发现有 TaskManager 心跳失联,随即出现作业崩溃重启,严重影响线上业务的运行。

TaskManager 突然失联(退出)TaskManager 突然失联(退出)

通过查看这个失联 TaskManager 的日志,发现它报了很多 ZooKeeper 连接超时的错误,随后的重试也不成功,所以 Flink 认为发生了严重的异常,主动令 TaskManager 退出。

TaskManager 的报错日志TaskManager 的报错日志

初步定位

由于观察到作业崩溃了不止一次,通过查看之前几次的运行日志,也看到了大量的 ZooKeeper 连接超时和报错情况,因此首先从 ZooKeeper 服务端入手分析。

经过排查,发现 ZooKeeper 服务端一切正常,没有任何报错日志,各类指标都处于健康状态。此外,假设如果 ZooKeeper 服务端出问题的话,同一个集群的其他作业很可能都受到波及,但并没有观察到其他作业有出错的情况,因此 ZooKeeper 服务端出问题的概率极小。

随后,分析了客户的 JAR 包,也并未发现有引入不兼容的 ZooKeeper Curator 版本库,因此客户端版本冲突等问题也基本排除。

那问题来了:究竟是什么原因,造成 ZooKeeper 连接超时,且重试也久久无法恢复呢?

继续收集报错信息

由于作业仍然在不断崩溃重启,从后面的运行实例中,又有一些新的发现:Kafka、Prometheus 监控上报端也有超时现象:

Kafka 也发生了超时Kafka 也发生了超时
Prometheus 监控上报超时Prometheus 监控上报超时

这些报错揭示了潜在的网络问题,例如容器所在宿主机的网卡出现故障,出现大范围的丢包、拥塞等,都会造成上述的报错。

但是诡异的是,故障 Pod 分布在不同的宿主机节点上,而这些宿主机上的其他 Pod 运行正常,且各个宿主机的流量监控也都处于正常范围,不像是某些故障节点造成的问题。

因此网络故障的猜想又一次被否定了。

直接原因浮现

既然环境方面出问题的概率极小,那还是从作业本身入手分析。通过查看作业上报的 Full GC 次数,发现明显不正常:

TaskManager 老年代 GC 次数TaskManager 老年代 GC 次数

TaskManager 正常情况下,老年代 GC 次数应该是个位数,或者十位数,但这里发现居然上千次,说明出现了极高的内存压力,且内存垃圾每次几乎清理不掉,造成 JVM 持续在做 GC。

而我们知道,当发生 GC 时,JVM 会有一段的停止时间(Stop The World),此时所有的线程会被暂停执行。如果 JVM 持续在做 GC,那正常线程就会受到严重影响,最终出现心跳包迟迟未能发出,或者连接无法保持而出现超时等现象。

那问题又来了:究竟是什么操作,造成内存压力这么大呢?

深入分析

既然发现了问题的直接原因是堆内存压力过大,GC 无法清理,那很可能出现了内存泄漏的现象。经典的内存泄露场景是用户在 List、Map 等容器中放入了过多的对象,这些对象由于强引用的关系,无法被清理,但是又持续占着内存空间。

这个作业由于崩溃比较频繁,问题持续可复现,因此可以在问题发生时,进入 Pod 对其进行 Heap Dump(例如使用 Java 自带的 jmap 命令),然后对这个 Dump 文件进行分析:

使用 JProfiler 分析 Dump 文件中对象的占用情况使用 JProfiler 分析 Dump 文件中对象的占用情况

从分析结果可以看到,有一个 HashMap 占了 96% 的空间,基本上把堆内存占满了。通过与客户沟通和授权,分析程序源码后,发现这个是用户自行实现的一个缓存池,随着数据的源源不断输入和 Watermark 的逐步推进,缓存内容会动态更替。当数据流入过多时,失效缓存清理不及时的话,就会对 GC 造成很大的压力。

不只是普通的容器对象会出现这个问题,Flink 自带的状态(MapState、ListState 等)也有可能因为 Watermark 推进过慢、窗口过大、多流 JOIN 的对齐等原因,变得异常庞大。如果没有设置 State TTL 等清理机制的话,也有可能造成 JVM 的不稳定(尤其是使用 Heap 状态后端时)。因此在 Flink 作业编程时,对于有可能积压大量状态的操作,一定要非常慎重。

如果因为业务逻辑难以减小状态总量,我们建议使用 RocksDB 状态后端(这也是腾讯云 Oceanus 平台目前的默认选择)。当然,相对于 Heap 状态后端而言,RocksDB 状态后端会带来更高的处理延迟和更低的吞吐量,因此需要结合实际场景来选择。

总结和思考

这次问题定位其实是走了弯路的,一开始的告警是以日志形式通知的,由于连续几个实例失败前都有大量的 ZooKeeper 报错,所以想当然地把定位重点放到了 ZooKeeper 相关的组件。后来发现其他组件也报了超时后,又把定位方向改为了网络故障,最终看了监控才发现是 GC 的停顿造成的。如果在着手定位问题前,先看一下 Flink 的监控数据,会更容易发现问题的成因。

因此,我们在定位问题时,一定要综合地从指标、日志、环境等方面收集数据,首先区分哪些报错和异常是直接原因(通常是最早发生的那个),哪些是间接和次生的故障。如果我们一开始就被后者吸引的话,就很可能一叶障目而不见泰山,分析了很久以后发现并不是问题所在。

例如 Flink 日志中常见的 IllegalStateException: Buffer pool is destroyed、InterruptedException 等报错,通常是其他问题发生后才出现的,那么我们可以忽略它们,继续往更早的日志中找问题,直到发现根因。

0 人点赞