Flink任务 checkPoint失败 问题排查记录

背景

公司有一个实时报表项目,需要使用到flink来进行处理。

处理逻辑大概如下:
需要使用canal监控多张表,然后进行一些复杂计算。

程序设置

flink程序代码里面设置了 checkPoint和自动重启机制

//checkpoint配置
env.enableCheckpointing(300000);
env.getCheckpointConfig().setCheckpointingMode(CheckpointingMode.EXACTLY_ONCE);
env.getCheckpointConfig().setMinPauseBetweenCheckpoints(500);
env.getCheckpointConfig().setCheckpointTimeout(60000);
env.getCheckpointConfig().setMaxConcurrentCheckpoints(1);
env.getCheckpointConfig().setTolerableCheckpointFailureNumber(5);       env.getCheckpointConfig().enableExternalizedCheckpoints(CheckpointConfig.ExternalizedCheckpointCleanup.RETAIN_ON_CANCELLATION);

env.setRestartStrategy(RestartStrategies.failureRateRestart(
                3,
                Time.minutes(5),
                Time.seconds(10)
        ));

但是任务跑一段时间之后,发现任务会一直失败重启。

排查过程

点击任务,进入详情页,查看Exceptions那个模块:

Caused by: org.apache.flink.util.FlinkRuntimeException: Exceeded checkpoint tolerable failure threshold.
    at org.apache.flink.runtime.checkpoint.CheckpointFailureManager.handleCheckpointException(CheckpointFailureManager.java:98)
    at org.apache.flink.runtime.checkpoint.CheckpointFailureManager.handleJobLevelCheckpointException(CheckpointFailureManager.java:67)
    at org.apache.flink.runtime.checkpoint.CheckpointCoordinator.abortPendingCheckpoint(CheckpointCoordinator.java:1915)
    at org.apache.flink.runtime.checkpoint.CheckpointCoordinator.abortPendingCheckpoint(CheckpointCoordinator.java:1888)
    at org.apache.flink.runtime.checkpoint.CheckpointCoordinator.access$600(CheckpointCoordinator.java:94)
    at org.apache.flink.runtime.checkpoint.CheckpointCoordinator$CheckpointCanceller.run(CheckpointCoordinator.java:2029)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

百度了之后解释说:是由于任务的checkpoint重试次数达到了给定的阈值,然后任务失败了。 难道是checkPoint设置有问题?

然后去查看 CheckPoints 这一栏:

点击 History ------》 点击 Refresh

查看任务最近的一次checkPoint情况。

发现任务的checkPoint 失败了5次。 程序里面设置的最多重试5次, 所以任务挂掉了(下面的是正常的checkpoint状态)
checkpoint_list

点击某一次checkpoint前面的 + 查看每个算子的checkpoint详情(失败的时候,是在某一个算子的地方出现)

在这里插入图片描述

可以查看到底是哪个算子在checkpoint的时候出现了问题。

确认问题原因

然后的排查思路就是: 先将任务下线,然后在代码中打印部分日志,修改算子链设置,将每个算子隔离开,并且去掉自动重启任务的配置,仔细查看checkpoint失败的算子的日志

然后将flink 代码修改 设置 禁止自动合并算子

env.disableOperatorChaining();

重新打包上传启动任务。

找到有错的算子这里。 点击它 ,然后进去查看他的日志
在这里插入图片描述

可以看到,在任务即将失败重启的时候,出现如下日志:

2021-06-16 15:07:26,168 WARN  org.apache.flink.runtime.taskmanager.Task                    [] - Task 'Interval Join (1/1)#0' did not react to cancelling signal for 30 seconds, but is stuck in method:
 java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
java.net.SocketInputStream.read(SocketInputStream.java:171)
java.net.SocketInputStream.read(SocketInputStream.java:141)
com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
com.mysql.jdbc.MysqlIO.nextRowFast(MysqlIO.java:2064)
com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1989)
com.mysql.jdbc.MysqlIO.readSingleRowSet(MysqlIO.java:3410)
com.mysql.jdbc.MysqlIO.getResultSet(MysqlIO.java:470)
com.mysql.jdbc.MysqlIO.readResultsForQueryOrUpdate(MysqlIO.java:3112)
com.mysql.jdbc.MysqlIO.readAllResults(MysqlIO.java:2341)
com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2736)
com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2487)
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858)
com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
com.report.util.DbUtil.queryKv(DbUtil.java:193)
com.report.function.HuiChatWindowFunction.processElement(HuiChatWindowFunction.java:495)
com.report.function.HuiChatWindowFunction.processElement(HuiChatWindowFunction.java:38)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.collect(IntervalJoinOperator.java:274)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.processElement(IntervalJoinOperator.java:248)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.processElement2(IntervalJoinOperator.java:208)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory.processRecord2(StreamTwoInputProcessorFactory.java:207)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory.lambda$create$1(StreamTwoInputProcessorFactory.java:176)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory$$Lambda$760/267817329.accept(Unknown Source)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory$StreamTaskNetworkOutput.emitRecord(StreamTwoInputProcessorFactory.java:277)
org.apache.flink.streaming.runtime.io.StreamTaskNetworkInput.processElement(StreamTaskNetworkInput.java:204)
org.apache.flink.streaming.runtime.io.StreamTaskNetworkInput.emitNext(StreamTaskNetworkInput.java:174)
org.apache.flink.streaming.runtime.io.StreamOneInputProcessor.processInput(StreamOneInputProcessor.java:65)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessor.processInput(StreamTwoInputProcessor.java:97)
org.apache.flink.streaming.runtime.tasks.StreamTask.processInput(StreamTask.java:396)
org.apache.flink.streaming.runtime.tasks.StreamTask$$Lambda$568/407559166.runDefaultAction(Unknown Source)
org.apache.flink.streaming.runtime.tasks.mailbox.MailboxProcessor.runMailboxLoop(MailboxProcessor.java:191)
org.apache.flink.streaming.runtime.tasks.StreamTask.runMailboxLoop(StreamTask.java:617)
org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:581)
org.apache.flink.runtime.taskmanager.Task.doRun(Task.java:755)
org.apache.flink.runtime.taskmanager.Task.run(Task.java:570)
java.lang.Thread.run(Thread.java:748)

2021-06-16 15:07:56,172 WARN  org.apache.flink.runtime.taskmanager.Task                    [] - Task 'Interval Join (1/1)#0' did not react to cancelling signal for 30 seconds, but is stuck in method:
 java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
java.net.SocketInputStream.read(SocketInputStream.java:171)
java.net.SocketInputStream.read(SocketInputStream.java:141)
com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
com.mysql.jdbc.MysqlIO.nextRowFast(MysqlIO.java:2064)
com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1989)
com.mysql.jdbc.MysqlIO.readSingleRowSet(MysqlIO.java:3410)
com.mysql.jdbc.MysqlIO.getResultSet(MysqlIO.java:470)
com.mysql.jdbc.MysqlIO.readResultsForQueryOrUpdate(MysqlIO.java:3112)
com.mysql.jdbc.MysqlIO.readAllResults(MysqlIO.java:2341)
com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2736)
com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2487)
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858)
com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
com.report.util.DbUtil.queryKv(DbUtil.java:193)
com.report.function.HuiChatWindowFunction.processElement(HuiChatWindowFunction.java:495)
com.report.function.HuiChatWindowFunction.processElement(HuiChatWindowFunction.java:38)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.collect(IntervalJoinOperator.java:274)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.processElement(IntervalJoinOperator.java:248)
org.apache.flink.streaming.api.operators.co.IntervalJoinOperator.processElement2(IntervalJoinOperator.java:208)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory.processRecord2(StreamTwoInputProcessorFactory.java:207)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory.lambda$create$1(StreamTwoInputProcessorFactory.java:176)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory$$Lambda$760/267817329.accept(Unknown Source)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessorFactory$StreamTaskNetworkOutput.emitRecord(StreamTwoInputProcessorFactory.java:277)
org.apache.flink.streaming.runtime.io.StreamTaskNetworkInput.processElement(StreamTaskNetworkInput.java:204)
org.apache.flink.streaming.runtime.io.StreamTaskNetworkInput.emitNext(StreamTaskNetworkInput.java:174)
org.apache.flink.streaming.runtime.io.StreamOneInputProcessor.processInput(StreamOneInputProcessor.java:65)
org.apache.flink.streaming.runtime.io.StreamTwoInputProcessor.processInput(StreamTwoInputProcessor.java:97)
org.apache.flink.streaming.runtime.tasks.StreamTask.processInput(StreamTask.java:396)
org.apache.flink.streaming.runtime.tasks.StreamTask$$Lambda$568/407559166.runDefaultAction(Unknown Source)
org.apache.flink.streaming.runtime.tasks.mailbox.MailboxProcessor.runMailboxLoop(MailboxProcessor.java:191)
org.apache.flink.streaming.runtime.tasks.StreamTask.runMailboxLoop(StreamTask.java:617)
org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:581)
org.apache.flink.runtime.taskmanager.Task.doRun(Task.java:755)
org.apache.flink.runtime.taskmanager.Task.run(Task.java:570)
java.lang.Thread.run(Thread.java:748)

大概是这个算子在进行处理的时候,30s没有任何反应,程序卡在了某个方法里面.

可以看到主要的问题在于 代码这一行 (HuiChatWindowFunction.java:495)

Map<String, String> member = DbUtil.queryKv(checkMemberSql, "mysql");

这里是代码里面一个逻辑 需要根据来的数据 去mysql表查询该数据是否满足条件

这个SQL大概是这样的:

select aabm.member_id, acm.contact_account from xxx aabm join xxxx acm where (aabm.member_id = "xxx") or (acm.method_type = 1 and acm.contact_account = "xxxx");

当时写代码时没有考虑到sql的执行效率的问题

这两张表 都比较大,其中一张 几百万的数据,所以如果是join + or的方式进行查询。 速度就会很慢

验证问题原因

从日志里面捞出某一次的查询sql。 去数据库里面进行查询,果然很慢,一直没有返回结果。

所以现在大概确定了,问题确实出在这里。

问题修复

既然 join + or的查询方式 容易长时间没办法返回,从而导致flink任务报错。

那么就把查询逻辑修改一下:

将这个join分开查询,

select * from xxx where member_id = "";
select * from xxx where method_type = 1 and contact_account = "xxxx";

修改之前,我还在数据库里面测试了一下, 基本是秒返回。
就不会出现 stuck的情况了

反思总结

刚开始只根据了 Exceptions里面的日志, 无法确定异常到底出现在哪儿。 误以为是程序checkPoint的设置问题。 一直在对 checkPoint参数进行调整。一开始是加长checkpoint 超时时间, 后面又是增加 checkPoint并行度, 都没有任何效果,浪费了太多时间。

后面慢慢从头到尾梳理之后,从程序里面打印更多的日志到Stdout,然后也实时监控 算子的日志,才算真正找到问题所在。

checkPoint超时失败只是表象,深层次的原因其实是因为任务长时间被阻塞,这才没办法进行checkPoint,所以体现出来的就是 checkpoint超时失败。

当单纯的 Exceptions的日志无法定位问题的时候(或者根据Exceptions里的日志定位到的地方修改之后没有作用), 需要将程序的日志尽量多的打印出来,在程序失败的时候 准确捞取当时的异常信息, 这样才能准确定位到问题所在

  • 8
    点赞
  • 17
    收藏
    觉得还不错? 一键收藏
  • 9
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论 9
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值