最近某hadoop集群多次出现机器宕机,现象为瞬间机器的sys cpu增长至100%,机器无法登录。只能硬件重启,ganglia cpu信息如下:

Hadoop作业 hadoop作业cpu过高_apache

首先怀疑有用户启动了比较奇葩的job,导致不合理的系统调用出现的问题。随后加了ps及pidstat信息收集job信息(公共集群蛋疼的地方),然后出现问题的时候,各类脚本已经无法工作,

一直没有抓到现场。

终于在某一次看到一台机器sys 瞬间增长,且机器还能登录。立马查看现场,发现竟然元凶是datanode:datanode一个进程占用cpu 1600%,sys cpu占用超过40%

 

Datanode的进程栈信息,大量dataxceiver线程block,并且都是在发送数据块过程中 getVisibleLength操作:

"DataXceiver for client /10.16.136.65:34464 [sending block blk_341818443393496218_612191861]" daemon prio=10 tid=0x00007f7500a33000 nid=0x4135 waiting for monitor entry [0x00007f74ec5a5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.hadoop.hdfs.server.datanode.FSDataset.getVisibleLength(FSDataset.java:1116)
        - waiting to lock <0x000000051237f860> (a org.apache.hadoop.hdfs.server.datanode.FSDataset)
        at org.apache.hadoop.hdfs.server.datanode.BlockSender.<init>(BlockSender.java:118)
        at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:271)
        at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:176)
   Locjava:118)
        at org.apache.hadoop.hdfs.server.datanode.DataXceiver.writeBlock(DataXceiver.java:394)
        at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:184)
   Locked ownable synchronizers:
        - None

从这里看,似乎并没有什么问题,只是大量线程堵塞在文件的操作上。问题依然没有进展。

这样大概持续了一段时间,发现出问题的机器有一个共同点,dmesg信息有大量此类log:

shrink_slab: xfs_buftarg_shrink+0x0/0x160 [xfs] negative objects to delete nr=-6

参考:http://www.ibm.com/developerworks/cn/linux/l-cn-pagerecycle/

函数 shrink_slab()

函数 shrink_slab() 是用来回收磁盘缓存所占用的页面的。Linux 操作系统并不清楚这类页面是如何使用的,所以如果希望操作系统回收磁盘缓存所占用的页面,那么必须要向操作系统内核注册 shrinker 函数,shrinker 函数会在内存较少的时候主动释放一些该磁盘缓存占用的空间。函数 shrink_slab() 会遍历 shrinker 链表,从而对所有注册了 shrinker 函数的磁盘缓存进行处理。

从实现上来看,shrinker 函数和 slab 分配器并没有固定的联系,只是当前主要是 slab 缓存使用 shrinker 函数最多。

也就是这些dmesg信息应该是在内存回收磁盘缓存页面阶段出现的。

而看到某数字公司的一篇文章,同为hadoop服务sys cpu过高:

http://blogs.360.cn/360xitong/2013/03/26/hadoop%E9%9B%86%E7%BE%A4system-cpu%E6%B6%88%E8%80%97%E8%BF%87%E9%AB%98%E9%97%AE%E9%A2%98%E5%88%86%E6%9E%90-by-%E6%9D%82%E8%B4%A7%E5%BA%97%E5%BA%97%E9%95%BF/

作者追查的原因为compact_zone,同样为内存管理。

并且IBM提到了CFS对java性能的影响:

http://www-01.ibm.com/support/docview.wss?uid=swg21372909

处理的办法是/proc/sys/kernel/sched_compat_yield置为1,而RHEL6上面貌似这个参数已经不生效。

综上,可以基本推断出,这个问题跟RHEL6的内存管理密切相关。我们对RHEL6内存管理相关的的参数调整:

(1)   关闭大页内存:echo never > /sys/kernel/mm/redhat_transparent_hugepage/defrag && echo never >  /sys/kernel/mm/redhat_transparent_hugepage/enabled

(2)   Vfs_cache置为零:/sbin/sysctl vm.vfs_cache_pressure=0

于是从内存管理入手,首先调整了vm.vfs_cache_pressure,将其改回默认值100,观察一天,果然dmesg里shrink_slab相关信息消失,并且改过的机器没有出现过宕机。因此问题定位为

内存cache回收。此参数在RHEL5上运行时一直置为0并运行平稳,RHEL6真是坑人啊。。

我们将vm.vfs_cache_pressure置为0,目的是让系统不要主动回收cache,以使hadoop进程有足够多的内存cache。对datanode和task性能有比较好的提升。如果恢复回默认值,性能会有很大的下降,用户又不干了。于是经过测试,将vm.vfs_cache_pressure调整为5--10,这样系统会倾向于主动回收一部分cache,同时hadoop也有足够的cache供进程用。也再没有出现sys cpu升高导致的宕机问题。