前段时间遇到了一个很诡异的发生的Map阶段的OOM异常，花了些时间才找到原因，这个简要记录一下。
先看log。
节点一的TaskTracker的log：
节点二的TaskTracker的log：
节点三的TaskTracker的log：
其他节点的TaskTracker中的log都和slave4的一样的：
故障分析：
OOM是一个比较常见的故障，其中发生在reduce阶段最为常见，最有可能是数据通过map函数后，shuffle到reduce端处理时由于分布问题导致某个分组的值太多出现OOM。另外，OOM也可能出现在DataNode进程上，这个属于比较罕见的情况，这个情况我就遇到过，是因为系统进程数配置的限制导致OOM的，具体情况可以看我这篇blog：http://zengzhaozheng.blog.51cto.com/8219051/1370125。对于上面的这个出现在Map阶段的OOM比较奇怪，一般在Map阶段不会出现OOM，因为一个Map task只处理一个split的数据的，而我们集群的block size只是配到64MB,照道理一个split size的大小应该为64MB左右（具体split size大小计算请看：http://zengzhaozheng.blog.51cto.com/8219051/1347777），从这点看来Map阶段不会出现OOM情况。从另外一方面看，Map阶段出现OOM的唯一地方就是通过io.sort.mb参数所控制的环形缓冲区当中，其对用的是Sort和spill环节，集群中环形缓冲区配到了500MB，整个虚拟机内存mapred.map.child.java.opts也配到了2G，照道理不会出现OOM。另外，为了安全起见还是通过改变这个2个参数去测测，结果还是意料之中出现OOM。
再回过头来看看日志，不同节点的TaskTracker的日志都有所不同，其中的节点一、二、三的共同点就是heap OOM和Buffer的读写错误,其他节点则都是报了一些文件错误。那么整个OOM错误的日志被归为2类，其中其他节点则都是报了一些文件错误很可能是由于节点一、二、三出现OOM引起的，具体原因还是要根据堆栈信息追一下源码，找到TaskLog类的createForWrite方法：
/**
* Open the specified File for write access, ensuring that it does not exist.
* @param f the file that we want to create
* @param permissions we want to have on the file (if security is enabled)
*
* @throws AlreadyExistsException if the file already exists
* @throws IOException if any other error occurred
*/
public static FileOutputStream createForWrite(File f, int permissions)
throws IOException {
if (skipSecurity) {
return insecureCreateForWrite(f, permissions);
} else {
// Use the native wrapper around open(2)
try {
FileDescriptor fd = NativeIO.open(f.getAbsolutePath(),
NativeIO.O_WRONLY | NativeIO.O_CREAT | NativeIO.O_EXCL,
permissions);
return new FileOutputStream(fd);
} catch (NativeIOException nioe) {
if (nioe.getErrno() == Errno.EEXIST) {
throw new AlreadyExistsException(nioe);
}
throw nioe;
}
}
}从这段源码我们可以看出TaskTracker在创建TaskLog的时候出现了错误，其原因是TaskLog句柄已经存在了。呵呵，这个不难理解，当Map Task出现OOM之后，根据MapReduce的容错机制，其所在的TaskTracker进程会尝试重新启动的Map Task并且为其创建相同的TaskLog的文件句柄，但是由于出现OOM程序异常终止了并且之前的TaskLog文件句柄已经创建过但是没有被正常关闭，所以在重启启动Map Task是会检测到已经存在该句柄，所以报这个错。到这里第二类错误日志信息原因已经被解决，接下来集中精力看这个OOM错误原因。
这种情况的Map阶段出现的OOM之前没有遇到过，一时没有什么头绪，回过头来看看写的HiveSql脚本，功能很简单就是统计一个省当天网关日志的上网uv，对号码字段（mdn）做了一个count distinct最后group by了一下，当天日志做完ETL后才300多G左右，300G多的数据不算大。再看了看节点一、二报的这2个OOM信息，发现有IO读写错误的信息，主要是BufferedReader读取和用StreamDecoder解码出错，这下子想到会不会是mdn字段值有问题，出现乱码什么的导致读写错误最终引起OOM呢？试验一把！！首先检查mdn长度，distinct length(mdn)看看，照道理应该只有一个值并且这个值为11才对因为号码是固定的13位数，令人惊奇的是出现了3个不同的值,分别为11、16和18！在HiveSql中加上where length(mdn)=11，将长度为16和18的排除掉，重新执行HiveSql相当正常一点错误都没有！！查看号码mdn长度为16和18的究竟长什么模样，分别执行select * from tb_cdr where day=‘20140403‘ and length(mdn)=16 limit 5 和 select * from tb_cdr where day=‘20140403‘ and length(mdn)=18 limit 5，发现记录中有些乱码，这下子搞明白了。Map Task运行的时候数据流中包含了非法字符例如：EOF、NOP等东西，导致BufferedReader读取和StreamDecoder解码出错，正如节点一、二日志中看到的，进一步导致OOM。
总结：
对于这个OOM故障,按照一般的MapReduce框架运行原理思维和平常的OOM故障处理方式是很难揪出问题所在的。解决这样问题的关键点在于日志中的细小信息点，如BufferedReader读取和StreamDecoder的出错点，你不能够一看到OOM就不往日志下面看了，这种细小信息可以引导你到一个正确的方向，不至于漫无目的的瞎搞。另外，搞hadoop方面的技术人员最好是要精通于写MapReduce程序，我觉得这个很重，会写MapReduce程序那么你对MapReduce的整体处理流程一定会很清楚，出现问题能够比较容易找出原因。如果只会HiveSql，那么出现简单的错误自己都无法下手搞的，甚至连简单的数据倾斜原理都不知道，这样你写的HiveSql性能也许很低效的，所以一切都需要回到本质问题上来，hive的本质就是将HiveSql翻译成MapReduce程序。
本文出自 “一只风骚的蚂蚁” 博客，谢绝转载！
记一则罕见的hive字段值异常引起map阶段的OOM,布布扣,bubuko.com
原文地址：http://zengzhaozheng.blog.51cto.com/8219051/1413583
