1. 问题描述

当前，我们通过编写Hadoop MapReduce程序对来自上游的源数据文件进行贴源预处理加工。源数据文件发到Hadoop集群后，我们的预处理程序会对源数据进行编码转换、数据去重、加时间拉链、数据清洗、错误数据处理等操作，生成贴源的ODS层数据，供上层建模使用。

一直以来系统运行稳定，未出现过问题。但一段时间以来部分源文件的预处理作业频繁出现作业长时间卡死的问题，导致Hadoop集群资源被长时间占用，其他作业因资源不足而无法正常调起，影响了预处理加工的时效性。对此我们从各方面进行了分析和处理，具体过程如下。

2. 问题分析

2.1. 数据倾斜可能性分析

当问题出现时，我们首先考虑到可能是因为数据倾斜问题导致了作业长时间卡死的现象。于是我们首先检查YARN控制台的作业信息如图2-1：

图2-1 YARN控制台reduce任务运行情况

从上图可以看到有大量的reduce任务长时间运行，而非少部分reduce任务长时间运行。数据倾斜的典型现象是大部分reduce任务执行时间较短，只有很少的reduce任务长时间运行，可以说上图反映的情况与数据倾斜并不完全相符，同时，我们也对MR程序处理的源数据文件进行了按Key值分组计算，发现并未有数据分布不均衡的情况，因此我们排除了因数据倾斜导致作业卡死的可能性。

2.2. Hadoop集群组件状态分析

通过查看Hadoop集群UI页面上各组件状态以及查看NameNode、DataNode、ResouceManager等系统服务日志信息，可以确认集群及各组件没有问题，运行正常，从而排除因集群本身问题导致作业卡死。

2.3. 日志分析

我们发现这些长时间运行的作业都是卡死在reduce阶段，有大量reduce任务卡在27%-30%进度不再运行，如图2-1所示。同时也有部分map任务和reduce任务失败。于是我们查看了该作业的如下日志信息：

1）通过yarn -logs获取的job日志：

2）job对应的容器日志为如图2-2和图2-3所示

图2-2 异常作业容器信息1

图2-3 异常作业容器信息2

3）失败map任务日志：

图2-4 失败map任务日志

4）失败reduce任务日志：

图2-5 失败reduce任务日志

5）长时间卡死的reduce任务的syslog日志：

6）长时间卡死的reduce任务的syslog.shuffle的日志：

7）长时间卡死的reduce任务的进程栈

根据上述日志进行如下分析：

（1）job日志中异常1：[communication thread] org.apache.hadoop.mapred.Task: Communicationexception。这个是任务的一种状态报告机制，当出现异常时会有重试机制（默认为3次）。后续没有出现异常，则说明已恢复正常，不需要关注.

（2）job日志中异常2：[communication thread]org.apache.hadoop.yarn.util.ProcfsBasedProcessTree: Error reading the streamjava.io.IOException: 没有那个进程。出现该异常信息后，任务持续卡住长达11小时，在任务界面上依然是running状态，原因不明。

（3）失败map任务和失败reduce任务日志显示任务超时，容器被killed，对应的进程退出码为143。从UI日志截图显示的任务超过10分钟无响应（对应yarn容器配置中mapreduce.task.timeout=10分钟)而被kill掉。该情况通常发生在任务高并发、IO竞争激烈的场景下，考虑优化超时时间、容器内存配置等参数。但该问题不是导致作业卡死的原因，如果超长reduce任务可以超时被kill也不会出现本文之前描述的情况。

（4）对于长时间卡死的reduce任务的syslog日志中“IOException: 没有那个进程”异常，一般是读取“/proc/meminfo”、“/proc/cpuinfo”等本地文件时出现，正常情况下任何用户都可以访问这些文件，初步诊断为可能是没有更多的文件描述符来打开/proc/下对应进程文件的信息。通过“ulimit -n”查询发现所有的节点配置所有用户对应的打开文件数为100000，在系统繁忙时可能有些偏少，后续考虑提升至150000。但这不是导致作业卡死的原因。

（5）通过查看长时间卡死的reduce任务的syslog.shuffle日志，可以发现对应的shuffle任务在较短的时间内就处理了大量的map结果，但是shuffer任务本身日志中并没有报错，呈现任务卡死现象，原因不明。

（6）因上述日志没有查到任务长时间卡死的线索，我们又查了卡死reduce任务进程的堆栈信息，从堆栈信息中，我们发现reduce任务获取map任务完成事件的线程状态是阻塞，也就是说reduce任务在等待map任务完成的信号但一直没收到，而事实上该job的所有map任务都已经完成，这导致整个作业卡死，在高并发情况下会偶现这种情况。之所以reduce没有触发超时kill机制是reduce任务的ping心跳发送本身并没有异常，而事件获取线程也并未退出（若因异常退出，会直接导致reducetask异常而重跑任务）。我们进一步查了job的如下三个参数：

ipc.client.ping=true

ipc.ping.interval=60000

ipc.client.rpc-timeout.ms=0 

因设置了基于TCP的Socket的网络超时时间，当任务节点读取数据时发生SocketTimeoutException时，会自动的向服务器端发送ping包，来测试当前客户端与服务器端的连接是否正常，对应的参数为ipc.ping.interval（默认为60000ms)。ipc.client.rpc-timeout.ms是RPC客户端等待相应的超时时间值，当参数的值为0时，在远程方法调用没有接受到数据的情况下，只要ping服务正常，就不会超时，而只会按ipc.ping.interval时间间隔不停发出ping服务，如果有ipc.client.rpc-timeout.ms>0,该时间内未收到远程方法返回的数据即超时，随即停止发送ping服务，从而可以有效避免卡死。当前集群ping发送机制是打开的，每1分钟定期向服务器发送ping服务，但是超时时间设置为0，即永不超时，会一直处于读取map数据的阶段，这也就是AM一直认为该reduce任务还活着而没有按照任务超时机制将其kill。这样问题的核心原因基本找到了。

2.4. 作业运行外围情况分析

在分析日志的同时，我们也关注了作业卡死时段的其他外围情况：

1）有大量作业在该时段被调起；

2）近期集群进行了扩容，正在进行数据均衡操作中，节点间IO竞争激烈；

3）鉴于hadoop的任务分配原则（本地数据优先，计算在数据所在节点上进行的原则），在任务高峰期，某些节点IO竞争激烈，会导致任务超时现象发生。

2.5. 分析小结

综上，可以得到如下结论：

1）ipc.client.rpc-timeout.ms=0参数设置不合理，无超时退出机制，导致在高并发、IO竞争激烈的场景下，触发了任务长时间卡死的问题；

2）节点文件描述符数偏低，导致任务执行中出现“IOException: 没有那个进程”异常；

3）超时时间、容器内存配置等参数不够优化，导致部分任务超时失败退出，影响job执行；

4）大量作业并发和数据均衡操作一定程度上加剧了IO的竞争程度，间接触发了卡死问题的出现。

其中1）是产生问题的主要因素。

3. 问题解决

问题原因找到就好制定处理方案了，我们通过控制作业并发、降低数据均衡操作带宽和调整如下集群参数来解决问题：

上述操作执行后，问题得到解决。

经过此次问题处理，我们也总结了一套针对Hadoop程序长时间执行问题的解决思路：

1、首先检查是否有数据倾斜，因为大部分情况下是由这个原因引发Hadoop程序长时间执行问题。数据倾斜的典型现象是大部分reduce任务执行时间较短，只有很少的reduce任务长时间运行，同时某个key对应的数据比其他key对应的数据多很多，一旦出现上述情况就可判断是出现数据倾斜情况，需要对key值特别多的数据进行单独处理，比如在key上加随机数把数据打散，使得数据尽可能的平均shuffle到各reduce节点上，充分利用各节点的算力。

2、如果未出现数据倾斜的情况，那就需要先检查集群各主要组件的运行情况，如HDFS、YARN、Spark、Hive等，确认各组件是否正常，有相当一部分Hadoop程序长时间执行问题由组件运行问题引起。一般通过查看Hadoop集群UI页面上各组件状态和查看各组件系统日志来判定组件运行是否有问题。

3、如果上述两项均无问题，我们就需要针对日志进行更为细致的分析了，重点需要查看job日志、容器日志、map和reduce节点日志、以及map和reduce任务的进程栈，尤其是任务的进程栈对一些疑难问题的分析解决有很大帮助。一般到这一步引起超时问题的原因就很多了，需要具体问题具体分析，但我们不妨重点检查是否是相关超时参数设置不合理导致，如以下参数

以上思考仅供参考，希望对大家解决问题有所帮助。