-
网易视频云
:HB
aseRegionServer
宕机案件侦查
今天网易视频云技术专家给大家分享一下
HBase
–
RegionServer
宕机案件侦查,欢迎参与
讨论。
本来静谧的晚上,
吃着葡萄干看着球赛,
何等惬
意。
可偏偏一条报警短信如闪电一般打
破了夜晚的宁静,线上集
群一台
RS
宕了!于是倏地从床上坐起来,看了看监控,瞬间惊
呆
了:单台机器的读写吞吐量竟然达到了
5w ops/sec
!
RS
宕机是因为这么大的写入量造成
的?如果真是这样,
它是怎么造成的?如果不是这样,
那又是什么原因?各种疑问瞬间从脑
子里一一闪过,甭管那么多,先把日
志备份一份,再把
RS
拉起来。接下来还是
Bug
排查
老套路:日志、监控和源码三管齐下,来看看到
底发生了什么!
案件现场篇
下图是使用监控工具
Ganglia
对事发
RegionServer
当时
读写吞吐量的监控曲线,
从图
中可以看出,大约在
19
点
~21
点半的时间段
内,这台
RS
的吞吐量都维持了
3w
ops/sec
左右,峰值更是达到了
6w ops/sec<
/p>
。之前我们就线上单台
RS
能够承受的最
大读写吞吐量
进行过测定,基本也就维持在
2w
左右,主要是因为网络带宽瓶颈。而在宕机前这台
RS
的
读写吞吐量超出这么多,直觉告诉我
RS
宕机原因就是它!
接着就赶紧把日志拉出来看,满屏的
responseTooSlow
,如下图所示:
很显然,这种异常最大可能原因就是
Full GC
,果然,经过耐心地排查,可以看到很多
如下所示的
Full GC
日志片段:
2016-04-14 21:27:13,174
WARN [JvmPauseMonitor] seMonitor:
Detected pause in JVM or host machine
(eg GC): pause of approximately 20542ms
GC pool
'ParNew' had collection(s): count=1 time=0ms
GC pool
'ConcurrentMarkSweep' had collection(s): count=2
time=20898ms
2016-04-14 21:27:13,174 WARN
[icFlusher]
r: We slept 20936ms instead
of 100ms, this is likely due to a long
garbage collecting pause
and it's usually bad, see
/#red
可以看出,
HBase
执行了一次
CMS GC
,导致整个进程所有线程被挂起了
20s
。通过
对
MemStore
的监控也可以看出这段时间
GC
力度之大,如下图所示:
GC
时间长最明显的危害是会造成上
层业务的阻塞,通过日志也可以看出些许端倪:
ption: Connection reset by
peer
at
0(Native Method)
(:39)
toNativeBuffer(:223)
(:197)
(:384)
at lRead(:2246)
at
ver$$dProcess(
va:1496)
....
2016-04-14
21:32:40,173 WARN
[r=125,queue=5,port=60020] ver:
dercallId: 7540 service:
ClientServicemethodName: Multi size:
100.2 K connection:
10.160.247.139:56031: output error
2016-04-14 21:32:40,173
WARN
[r=125,queue=5,port=60020] ver:
r=125,queue=5,port=60020: caught a
ClosedChannelException, this means that
the server was processing a request but
the client went away. The error message
was: null
上述日志表
示
HBase
服务端因为
Full G
C
导致一直无法响应用户请求,用户客户端程
序在一定时间过后
就会
SocketTimeout
并断掉此
Connection
。连接断掉之后,服务器端
就会打印
如上日志。
然而,
这些和我们的终极目标好像并没有太大关系,
别忘了我们的目标
是找到
RS
宕机的原因哦!
破案铺垫篇
经过对案件现场的排查,唯一有用的线索就是
HBase
在宕机前经历了很严重、很频繁
的
Full
GC
,从下面日志可以进一步看出,这些
Full
GC
都是在
concurrent
mode failure
模式下
发生的,也就是虚拟机还未执行完本次
GC
的情况下又来了大量
数据导致
JVM
内存
不够,此时虚拟机
会将所有用户线程挂起,执行长时间的
Full
GC
!
(concurrent mode failure):
45876255K->21800674K(46137344K), 10.0625300
secs] 48792749K->21800674K(49283072K),
[CMS Perm :
43274K->43274K(262144K)],
10.2083040 secs] [Times: user=12.02 sys=0.00,
real=10.20 secs]
2016-04-14 21:22:43,990
WARN [JvmPauseMonitor] seMonitor:
Detected pause in JVM or host machine
(eg GC): pause of approximately 10055ms
GC pool
'ParNew' had collection(s): count=2 time=244ms
GC pool
'ConcurrentMarkSweep' had collection(s): count=1
time=10062ms
上文提到
Full GC
会对上层业务
产生很严重的影响,
那有没有可能会对下层依赖方也产
生很大的
影响呢?事实是
Yes
!而且,
RS<
/p>
宕机的大部分原因也要归咎于此!
进一步查看日志,发现
HBase<
/p>
日志中出现下述异常:
2016-04-14 21:22:44,006
WARN [ResponseProcessor for block
BP-63
2656502-10.160.173.93-42:blk_1073941840_201226]
ent: DFSOutputStreamResponseProcessor
exception for block
BP-632656502-10.160
.173.93-42:blk_1073941840_
ception: Bad
response ERROR for block
BP-632656502-1
0.160.173.93-42:blk_1073941840_201226 from
datanode 10.160.173.93:50010
-
-
-
-
-
-
-
-
-
上一篇:叠字成语
下一篇:如何使用QT播放视频