记一则神秘JDK版本引发的hadoop集群慢性崩溃”血案“

一、症状表现

   前些时间公司在外省机房部署了一套新hadoop集群，所有机子都装的是centos，跑了一个礼拜莫名其妙的出现了计算节点的心跳间隔变得越来越大，最终导致计算节点挂掉，遇到问题第一时间就是看日志...

二、解决思路

（1）看NameNode日志，一切正常。

（2）看心跳间隔大的节点上的taskTracker日志，转到计算节点一切正常。

（3）看心跳间隔大的节点上的dataNode日志,转到计算节点，并没有任何异常。

我就纳了闷啦，所有节点上日志看不出有任何异常。于是去看syslog日志信息，截了一段如下（节点一的信息slave01）：

都是一些系统内核运行日志，也没有任务异常信息。继续查，用lsof看看计算节点打开的文件数目，这下子惊呆了，严重超标，竟然达到了385433。打开文件数远远超出系统设定的值81920：

具体看看具体打开的都是一些什么文件（部分截图）:

相当奇怪，打开的几乎都是socket文件，而且打开的socket文件数只增不减。按照正常没有任何其它占socket连接的运行程序跑的情况下各个计算节点打开的socket文件数目应该为：1(TaskTracker数)+1(dataNode数)+Child数(正在节点上运行的task数)。以节点二为例，有一个Task在跑，如下图，打开的socket文件数就应该为：1+1+1=3个。

为什么会出现这种情况，是有人写的mapreduce程序打开socket没有关闭？为了排除这种情况，在集群中用hive进行一个简单的sql查询，再观察打开的socket文件数，结果一查打开的socket文件数还是只增不减，现在可以排除人为性打开socket不关闭的情况了。回头再瞄了一眼之前那个节点一打开socket文件的截图，这时候发现这些socket文件的进程号都和节点一上的datanode进程号是一样的，一个datanode打开了这么多socket文件？。一开始以为是bug，但是其他公司用我们hadoop1.2版本的就没有这个问题，这点应该可以排除掉。

   hadoop日志木有任何异常信息，系统日志木有任何信息！第一次见到种问题。上网查了下，发现有一个错误说法蛮像的，连接：http://my.oschina.net/JJREN/blog/78351，说是和centos的驱动版本有关系，于是毫不犹豫地将一台计算节点的网卡驱动升级了，再测，还是一个鸟样。这是要闹哪样啊!!!hadoop1.2在我们公司的另外一个装ubuntu集群中运行得没有任何问题，为何部署到centos上就会出现这种问题？难道是系统问题，这个一定不可能发生的，n家公司都是这个用，都没有问题。再到计算节点看看JDK版本是否一致，结果都是一致的，但是....这里高潮来了。发现了一个奇怪的问题，所有节点的JDK都是ea版的！！如图：

正常线上集群怎么装的是ea版的，这个相当不合理啊！！于是去问之前装系统的同事。他说这个JDK安装文件和另外一个部署在ubuntu的hadoop集群时的安装文件是一样的。于是，立马上上部署在ubuntu上的集群看JDK版本，一看主版本号都一样，但不是ea版本并且构建版本号不同。如图：

我就奇怪啦，同一个JDK安装文件在centos和ubuntu上安装会产生不同的版本号？？（其实我怀疑是安装的同事忘了，安装文件应该是不一样的）于是将ubuntu上已经安装好的JDK复制到部署在centos上的集群，配置hadoop-env.sh文件，将hadoop的JDK环境指向新更新后非ea版的JDK。重启集群，跑任务，测试，一切正常。看打开的socket文件数，如下:

打开的socket文件数=1(DateNdoe)+7(child)+1(TaskTracker)=9个，打开的socket文件数完全正常了，并且进程号都对上了，集群也恢复正常！！！搞定收工！！！！！

三、总结

   对于像这种非常规性集群出错并且没有任何日志异常信息的情况，真的不容易找到问题原因。但是解决问题的思路都是一样的，先查hadoop日志看能不能查到原因，如果查不到原因就要看借助linux自带的工具了，如lsof,strace,systat,netstat等。另外，syslog中的信息也是十分重要的，如果只看hadoop的log4j日志有可能永远都找不到故障原因，因为log4j所记录的是hadoop服务层的日志信息，它无法记录更加底层的日志信息。最后，一个程序猿的直觉也是十分重要的，在你用尽了所有你能想到的方法，查遍了网络上所有有关的信息都无法找到故障原因时，这种直觉往往会其到重要的作用，它会引导你往另外一个可能找到问题原因的方向去思考。但是我觉得这种直接不是凭空而来的，而是从日常的工作经验中积累的。