关键词:hbase jvm gc regionserver wal pause
背景:
HBase 1.1.2
客户的hbase集群最近出现RegionServer宕机情况。跟踪了master和RS日志发现,RS端抛出在做wal flush的时候,找不到 /apps/hbase/data/WALs/host,16020,timestamp 这个目录,由Parent directory doesn't exist 导致了 cannot get log writer,从而 RS abort。
master日志发现,找不到的那个log文件在上午11点的时候 被archive到oldWALs里,而且注意rs的wal目录带有splitting后缀。
2017-06-17 11:01:08,966 INFO [main-EventThread] wal.WALSplitter: Archived processed log hdfs://wgzx/apps/hbase/data/WALs/hdp034.wgzx,16020,1494436736930-splitting/hdp034.wgzx%2C16020%2C1494436736930.default.1497667888987 to hdfs://wgzx/apps/hbase/data/oldWALs/hdp034.wgzx%2C16020%2C1494436736930.default.1497667888987 2017-06-17 11:12:04,251 DEBUG [hdp013.wgzx,16000,1494436739211_ChoreService_1] master.ReplicationLogCleaner: Didnt find this log in ZK, deleting: hdp034.wgzx%2C16020%2C1494436736930.default.1497667888987
rs日志发现11点到16点中间没有日志,卡在了jvm pause,16点后开始flush11点被master delete的日志,宕机。
分析:
基本可以确定RegionServer就是不知为何卡住(不能确定是full gc),被stop-the-world了,然后master得不到RS的响应,以为它挂了,于是开始rename其WAL directory,做log split。(splitting后缀表示log split,表示master认为rs挂了) 然后rs起来打算继续11点时pause的工作,结果wal目录都没了,宕机。
卡顿几小时,而且printGCDetails的正常的gc日志也没打出来,让我们十分怀疑是不是真的是因为gc引起的,因为20g堆内+20g堆外也不算很大,就算gc性能再低,也不至于卡几小时。咨询了几位外部专家,表示都怀疑可能是遇到系统内核或jvm的bug了。但/var/log/message下异常当天没发现异常日志。
系统内核在CentOS 6.6 有个内核版本的bug,会导致进程卡死 : https://groups.google.com/forum/#!topic/mechanical-sympathy/QbmpZxp6C64 。但我们的是 Cent 6.7,在列表里明确表示是解决了这个bug的。
目前暂无法得知原因,而且在这个集群的HBase貌似是会偶尔出现这种情况,不止一台机器。我们内部集群HBase配置基本一样,反而没遇到过这类问题。
后续更新:
后来运维自己发现自己由于年初某一次故障,写了个定时去对regionServer做jmap的脚本(而且间隔时间据说只有分钟级)。把这个脚本去掉后貌似持续了半个多月再也没发生过问题。。。虽然jmap会触发fullGC,但是讲道理也不应该出现卡这么久,不知道是不是人为触发STW太频繁导致JVM产生了什么bug。