一个存疑的Hive Case——MapRedTask Slow

线上Hadoop做压缩格式更新，默认的从GZip转到Snappy，并重启了HDFS/MAPREDUCE集群，突然发现一个Hive Script Job从原来的12分钟缩短到4分钟并稳定跑了2天，并且该Job agent Server上的所有Hive Script Job的运行时间都缩短了；首先分析变更前后两天Job的MAPREDUCE日志，发现MAPREDUCE只变快了4分钟（因为Snappy的低压缩比导致了增加了一个REDUCER而把一个最慢的step加快，该哭还是笑呢：P），另外那诡异的4分钟在哪里消失了呢？

对比了两天的Job运行日志发现变化之前每个Job Stage之间的时间间隔在30s+，而维护后这个时间在3s以内，第一反应就是怀疑是不是JobTracker的问题，在确认了从生成Job，提交Job到Job完成的时间都是正常的，并且Job在准备文件的过程中对HDFS的操作也是确认正常，GC正常，排除掉JT的问题同时也排除了Namenode的问题；再进一步发现Hive的MoveTask/Stats Task也是1s完成，掐头去尾后定位到是在MAPREDUCE已经被JobTracker确认完成后，但是Hive被block了接近30s（=10×（pullinterval+checkpollinterval））才确认完成！（counterplan在隔了30s才打印，也就是说runningJob isNotCompleted）.

然后查看了其他的Hive agent Server的日志发现都一直正常，那么范围进一步缩小就是这台有问题，结合上面的分析有几点可能：

1.JT到agent网络不稳定——是否调整过有待确认，不过查看sar无错误包等，流量正常，看MR源码waitingforComplete的interval默认是在5s，如果是网络问题应该retry了5，6次；

2.Hive所在服务器问题

3.Hive本身问题

对于2服务器本身的流量/IO/LOAD都不高，余量很充分，并且2无错误日志，找一台对比OS参数发现太多不一样的了(坑)直接忽略掉，假设没问题，存疑；

对于3直接看Hive代码了，假设没1的问题，Hive在polltask的过程中有一个Bug（HIVE-4000），就是runningQueue不是线程安全的，可能导致racecondition进而会block住Hive；并且从

context switch/sec：

<a href="http://blog.51cto.com/attachment/201310/000430922.png" target="_blank"></a>

和Interupted/sec：

<a href="http://blog.51cto.com/attachment/201310/000458508.png" target="_blank"></a>

上看确实维护后降低了，也就是Sleep时间（此处Hive代码注释错误，每2秒而不是10秒进行一次poll）降低了，但是如果是Bug那应该是随机的，为什么单单这一台在维护之前有问题，所以这个解释不通，那这个cs降低应该是“果”而不是“因”，因此最可能的还是1，2网络层面的问题

问题分析到这里虽然还没有一个完美的答案，但是还是暴露一些问题：比如参数不统一，比如一些不合理的设置和监控的缺失，不过对HIVE/MAPREDUCE/HDFS梳理更清晰了.经验值确实值1000了：）

本文转自MIKE老毕 51CTO博客，原文链接：http://blog.51cto.com/boylook/1303926，如需转载请自行联系原作者