Spark Yarn ApplicationMaster 超时退出

问题说明

Spark 应用运行失败，查看 Spark UI 界面，发现任务执行正常，没有失败的 Job 和 Task。

问题分析

1. 查看 Yarn ResourceManger 的日志

从 Spark UI 界面中没有看到失败的 Job 和 Task，查看 Driver 日志看到 ApplicationMaster: RECEIVED SIGNAL TERM 信息，怀疑 Spark 应用被 kill 了，所以查看了 Yarn ResourceManger 日志，可以看到 Yarn 判断 ApplicationMaster 心跳超时导致，发送 TERM 信号。

Expired:appattempt_1623809535012_3914039_000001 Timed out after 90 secs

2. 分析 Spark ApplicationMaster 代码

ApplicationMaster 代码中启动 Reporter 线程调用 org.apache.spark.deploy.yarn.ApplicationMaster#allocationThreadImpl 方法，通过 while 循环向 Yarn 发送心跳。

怀疑是不是 Reporter 线程挂掉了，查看代码可确定日志中 Reporter 关键字，在 Driver 日志中并未发现异常退出信息。后直接在日志中查找 ApplicationMaster 关键字，发现如下信息：

21/07/26 16:00:21 INFO ApplicationMaster: Final app status: SUCCEEDED, exitCode: 0

21/07/26 16:00:21 INFO SparkContext: Invoking stop() from shutdown hook

........

21/07/26 16:02:02 ERROR ApplicationMaster: RECEIVED SIGNAL TERM

可以看到先打印了 SUCCEEDED 状态，刚好大约 90s 后接收到 TERM 信号。

查看 ApplicationMaster 代码，在用户包的 main 方法执行完成后，改变为成功状态，并设置 finished=true，从而导致 Reporter 线程正常退出。

val userThread = new Thread {
      override def run() {
        try {
          if (!Modifier.isStatic(mainMethod.getModifiers)) {
            logError(s"Could not find static main method in object ${args.userClass}")
            finish(FinalApplicationStatus.FAILED, ApplicationMaster.EXIT_EXCEPTION_USER_CLASS)
          } else {
            mainMethod.invoke(null, userArgs.toArray)
            finish(FinalApplicationStatus.SUCCEEDED, ApplicationMaster.EXIT_SUCCESS)
            logDebug("Done running user class")
          }
        } catch {
......

成功状态后进程并未退出，可以看到 SparkContext.stop() 方法在 main 方法执行完成后在执行的，由于 SparkContext 中添加 ShutdownHook 执行 stop() 方法。

解决

通过上面分析得出结论，由于在执行完用户包的 mian 方法后，Reporter 线程退出，执行 SparkContext.stop() ，并且 SparkContext.stop() 方法执行时间超过 90s (yarn.am.liveness-monitor.expiry-interval-ms)，导致 Yarn 认为 ApplicationMaster 超时，向 ApplicationMaster 发送 TERM 信号，停止任务。

根据以上结论，让用户在程序结束时显示调用 SparkContext.stop() 解决问题。

后续

继续排查 SparkContext.stop 慢的原因，发现大量 AppStatusListener 异常信息，怀疑是 AppStatusListener 接收到了太多的事件，导致处理过慢。

查看 SparkUI 界面，发现 Stage 的 task 数量很多，并且执行时间都非常短，查看用户配置，发现 spark.sql.shuffle.partitions 参数设置太大，用户修改后程序正常。