交换机引起的hbase事故

最近我们的hbase集群(0.98)突然出现写入很慢的情况。折腾了好几天。

症状

用户反应写入时快时慢,甚至有时无法写入。客户端的异常:

1
2
3
4
5
6
7
Failed after attempts=2, exceptions: Thu Apr 02 16:02:39 CST 2015, org.apache.hadoop.hbase.client.RpcRetryingCaller@6f1d91e9,
java.net.SocketTimeoutException: Call to hbase9.photo.163.org/10.160.128.137:60020 failed because
java.net.SocketTimeoutException: 5000 millis timeout while waiting for channel to be ready for read. ch :
java.nio.channels.SocketChannel[connected local=/10.164.140.76:60951 remote=hbase9.photo.163.org/10.160.128.137:60020]
Thu Apr 02 16:02:45 CST 2015, org.apache.hadoop.hbase.client.RpcRetryingCaller@6f1d91e9,
java.io.IOException: Call to hbase9.photo.163.org/10.160.128.137:60020 failed on local exception:
org.apache.hadoop.hbase.ipc.RpcClient$CallTimeoutException: Call id=19306, waitTime=6029, rpcTimetout=5000

还有些其他的异常,比如Connection reset by peer之类的。

这个问题是突然出现的,我们没有改过任何配置或硬件。

排查

第一反应是看下相关机器的负载。但CPU/内存/磁盘IO/网络IO等都很空闲。这个hbase集群很小,只有4台机器(hbase8/9/10/11),负载很低。不太可能是资源不足。

然后从hbase本身入手。从日志里统计下每小时flush的数据量,发现确实有下降。
但服务端日志中没有异常。我们已经关掉major compaction,关掉自动split,memstore、hlog等参数也调整过,应该不是hbase本身的机制阻塞了写入。

另一个可能是regionserver的FGC。但看监控平台上最长的FGC也没有超过1s。结合gc日志,也看不出什么问题。

不得不说我们对hbase本身的监控很少,基本为0。出现问题之后很难定位。机器/进程/JVM层面我们有自己的监控系统,各种信息很详细,但hbase的问题,很多时候只能靠猜。怀疑过WAL/AutoFlush/zookeeper/kerberos/TCP CLOSE_WAIT等等各种问题,然后又一一否决,浪费了很多时间。

联想到客户端的SocketTimeOutException,怀疑是客户端的网络问题。登陆到用户的机器上模拟压力测试,确实有问题。写入很慢,而且会抛异常。
但换了几台机器压测也有同样的问题。可见不是客户端网络问题,而是服务端的问题。

偶然发现压测时,regionserver的flush日志里,flush用时很长,一般要几十秒,长的甚至200秒以上。这很不正常,我们的memstore是128M,从内存里dump 128M的数据写到hdfs上(可能还要做下压缩),不应该这么慢。
于是怀疑是hdfs比较慢,写了个程序在hdfs上写1GB的文件,hbase的hdfs大概要用100s,甚至有时候会用到200s。而在另一个测试集群的hdfs上,大概只用10s。

确认是hdfs的问题就好办了,我对hdfs比hbase熟悉的多。首先hdfs是可以正常读写的,日志中也没有异常,应该不是DN本身的问题。那为什么写入会慢?hdfs在默认的3副本情况下,会挑选3个DN组成一个pipeline,一个packet必须同时写到3个DN上才能ack。凭直觉,猜测是DN节点间的网络有问题。
在hdfs上写一个单副本的1GB文件验证自己的想法(DN之间不会有数据传输),用时稳定在5s左右,可见确实是DN网络问题。
在不同的节点之间互相scp,发现某些节点之间scp的速度非常不稳定,快的时候30M/s,慢的时候会降到5M/s。也能证实网络有问题。

找运维部的一个大神看了下网络,他推测这4台机器处于不同的交换机上,导致网络不稳。还给我画了张拓扑图。。。
当时是周五下班了,只能等下周找机房的人确认下。

解决

下周上班后联系SA、机房的人一起看下这几台机器的网络。证实了确实处于两个交换机下。hbase8/10在一个交换机下,hbase9/11在另一个交换机下。和大神画的拓扑一样。。。
据机房的人说交换机的型号是4×1G,我也不太懂是什么意思。这个应该指的是交换机之间的带宽吧。同一个交换机下的机器,应该是能达到网卡速度的上限的。
可能是这2个交换机下其他机器流量突然变大了。
跟机房协商把这4台机器换到一个交换机下,网络瞬断下即可。
然后再次压测hbase,写入恢复了,也不会再出现SocketTimeoutException。
hdfs写入3副本的1GB文件也能稳定在9~10秒。

反思

其实这次的问题很简单,就是跨交换机的网络问题。但发现这个问题用了很多时间。

找问题时,首先要有监控。监控未必能告诉你哪里有问题,但能告诉你哪里没问题。这次的事故就是对hbase的监控不足,浪费了很多时间。
其次,还是要仔细看日志。不能只看日志里的ERROR。这次的事故就是很偶然的看到了flush的时间不正常。从另一个方面来说,这也是监控。如果我们能对flush的时间有个监控,也能很快发现问题。
最后,很多时候运维还是要凭直觉的。但这种直觉建立在经验的积累上,建立在对系统的熟悉程度上,而不是乱猜。像我发现hbase的问题时,就是乱猜浪费很多时间;但发现hdfs的问题时,只一次就猜到了DN的网络问题。说到底还是对hbase不熟。

延伸

我们以前没太注意过网络问题。这次事故后要把其他hadoop集群的网络状况也排查一遍。。。
hadoop本身虽然有rack awareness的机制,但我们一直没开启过,所有机器都是/default-rack。
其实跨交换机的问题是无法避免的。好像一个交换机最多只能接48台机器?而且机房也不会预留接口/机架之类的。
只能根据需要扩容交换机。