作者 | 介龙平,英文名 leo,码农一枚
【Arthas 官网社区正在举办征文活动,加入即有奖品拿~ 点击投稿】
1. 异样突起
HBase 集群的某一个 RegionServer 的 CPU 使用率忽然飙升到百分之百,独自重启该 RegionServer 之后,CPU 的负载依旧会逐步攀上高峰。屡次重启集群之后,CPU 满载的景象仍然会复现,且会继续居高不下,缓缓地该 RegionServer 就会宕掉,缓缓地 HBase 集群就完犊子了。
2. 异样之上的景象
CDH 监控页面来看,除 CPU 之外的简直所有外围指标都是失常的,磁盘和网络 IO 都很低,内存更是短缺,压缩队列,刷新队列也是失常的。
普罗米修斯的监控也是相似这样的,就不贴图了。
监控指标里的数字,只能直观地通知咱们景象,不能通知咱们异样的起因。因而咱们的第二反馈是看日志。
(企业微信截图)
与此同时,日志中还有很多相似这样的烦扰输入。
起初发现这样的输入只是一些无关紧要的信息,对剖析问题没有任何帮忙,甚至会烦扰咱们对问题的定位。
然而,日志中大量 scan responseTooSlow 的正告信息,仿佛在通知咱们,HBase 的 Server 外部正在产生着大量耗时的 scan 操作,这兴许就是 CPU 负载高的首恶。可是,因为各种因素的作用,咱们过后的关注点并没有在这个下面,因为这样的信息,咱们在历史的时间段里也频繁撞见。
3. 初识 arthas
监控和日志都不能让咱们百分百确定 CPU 负载高是由哪些操作引起的,咱们用 top 命令也只能看到 HBase 这个过程耗费了很多 CPU,就像下图看到的这样。
如果不做进一步剖析,你依然不晓得,问题呈现在 HBase 相干过程下的哪些执行线程。Java 中剖析过程的命令,能够应用 jstack
或 jstat gcutil
等。然而,明天要介绍的配角不是这俩,甚至不是 async-profiler
,而是 arthas
。async-profiler
尽管也是一个很弱小的工具,然而 arthas
蕴含了它,且性能更弱小,堪称神器。
arthas
很早以前就据说过,起初认为它只能用来剖析 WEB 利用,例如 Spring Boot,这两天认真翻看其官网文档之后,才感觉本人是如许的无知。arthas
的相干介绍和入门应用,请参考其文档,它的官网文档比任何第三方材料都具体和敌对。
- https://github.com/alibaba/arthas
- 阿尔萨斯官网文档
- https://github.com/jvm-profiling-tools/async-profiler
4. 用 arthas 来剖析 HBase 的异样过程
4.1 运行 arthas
java -jar /data/arthas/arthas-boot.jar --target-ip 0.0.0.0
- –target-ip 默认 127.0.0.1,此处赋值为 0.0.0.0 是为了应用 webconsole
4.2 arthas 运行胜利的界面
命令 top 定位到的异样的 HBase 过程 ID 是 1214,该过程就是 HRegionServer 的过程。输出序号 1,回车,就进入了监听该过程的命令行界面。
4.3 dashboard
运行 dashboard 命令回车,就能够查看该过程占用资源的总体状况,能够从图中看到,ID 为 59 的线程,占用的 CPU 最高。
4.4 thread
输出 thread 命令回车,查看该过程下所有线程的执行状况。
4.5 thread -n 3
输入资源占用前三名的线程。
4.6 thread -n 3 -i 5000
单位工夫为 5 秒内,资源占用前三名的线程。
4.7 应用 async-profiler 生成火焰图
生成火焰图的最简略命令。
profiler start
隔一段时间,大略三十秒。
profiler stop
在 web console 里查看。
对于火焰图的入门级常识:
查看 jvm 过程 cpu 火焰图工具。
火焰图里很分明地定位到 CPU 工夫占用最高的线程是绿框最长的那些线程,也就是 scan 操作。
5. scan 操作引起的 CPU 负载过高
通过以上的过程剖析,咱们最终能够确定,scan 操作的产生,导致 CPU 负载很高。咱们查问 HBase 的 API 基于 happybase 封装而成,https://happybase.readthedocs.io/en/latest/
其实惯例的 scan 操作是能失常返回后果的,产生异样查问的表也不是很大,所以咱们排除了热点的可能。形象进去业务方的查问逻辑是:
from happybase.connection import Connection
import time
start = time.time()
con = Connection(host='ip', port=9090, timeout=3000)
table = con.table("table_name")
try:
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='\x0f\x10&R\xca\xdf\x96\xcb\xe2\xad7$\xad9khE\x19\xfd\xaa\x87\xa5\xdd\xf7\x85\x1c\x81ku ^\x92k',
limit=3))
except Exception as e:
pass
end = time.time()
print 'timeout: %d' % (end - start)
PrefixFilter 和 row_start 的组合是为了实现分页查问的需要,row_start 的一堆乱码字符,是加密的一个 user_id,外面有特殊字符。日志中看到,所有的耗时查问,都有此类乱码字符的传参。于是,咱们猜测,查问呈现的异样与这些乱码字符无关。
然而,后续测试复现的时候又发现。
# 会超时
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='27', limit=3))
# 不会超时
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='27381095', limit=3))
也就是,即便不是乱码字符传参,filter 和 row_start 组合异样,也会导致 CPU 异样的高,row_start 指定的过小,小于前缀,数据扫描的范畴预计就会变大,相似触发了全表扫描,CPUload 势必会变大。
6. 频繁创立连贯或应用线程池造成 scan 线程持续增长
咱们操作 HBase 的公共代码是由 happybase 封装而成,其中还用到了 happybase 的线程池,在咱们更深刻的测试中又发现了一个景象,当咱们应用连接池或在循环中反复创立连贯时,而后用 arthas 监控线程状况,发现 scan 的线程会很重大,测试代码如下:
6.1 连贯在循环内部创立,重复使用
from happybase.connection import Connection
import time
con = Connection(host='ip', port=9090, timeout=2000)
table = con.table("table")
for i in range(100):
try:
start = time.time()
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='\x0f\x10&R\xca\xdf\x96\xcb\xe2\xad7$\xad9khE\x19\xfd\xaa\x87\xa5\xdd\xf7\x85\x1c\x81ku ^\x92k',
limit=3))
except Exception as e:
pass
end = time.time()
print 'timeout: %d' % (end - start)
程序开始运行时,能够关上 arthas 进入到 HRegionServer 过程的监控,运行 thread 命令,查看此时的线程应用状况:
小局部在运行,大部分在期待。此时,CPU 的负载状况:
6.2 循环在外部频繁创立而后应用
代码如下:
from happybase.connection import Connection
import time
for i in range(100):
try:
start = time.time()
con = Connection(host='ip', port=9090, timeout=2000)
table = con.table("table")
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='\x0f\x10&R\xca\xdf\x96\xcb\xe2\xad7$\xad9khE\x19\xfd\xaa\x87\xa5\xdd\xf7\x85\x1c\x81ku ^\x92k',
limit=3))
except Exception as e:
pass
end = time.time()
print 'timeout: %d' % (end - start)
下图中能够看到开始 RUNNING 的线程越来越多,CPU 的耗费也越来越大。
此时 CPU 的应用状况,由方才的较为安稳,陡然回升:
6.3 连接池的形式拜访 HBase
CPU 被之前的试验拉高,重启下集群使 CPU 的状态复原到之前安稳的状态。而后持续咱们的测试,测试代码:
没有超时工夫
from happybase import ConnectionPool
import time
pool = ConnectionPool(size=1, host='ip', port=9090)
for i in range(100):
start = time.time()
try:
with pool.connection(2000) as con:
table = con.table("table")
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='\x0f\x10&R\xca\xdf\x96\xcb\xe2\xad7$\xad9khE\x19\xfd\xaa\x87\xa5\xdd\xf7\x85\x1c\x81ku ^\x92k',
limit=3))
except Exception as e:
pass
end = time.time()
print 'timeout: %d' % (end - start)
如果不指定超时工夫,会只有一个线程继续运行,因为我的连接池设置为 1。
CPU 的负载也不是太高,如果我的连接池设置的更大,或者我的并发加大,那么这些耗时 scan 的线程应该会更多,CPU 使用率也会飙升。
指定超时工夫
from happybase import ConnectionPool
import time
pool = ConnectionPool(size=1, host='ip', port=9090, timeout=2000)
for i in range(100):
start = time.time()
try:
with pool.connection(2000) as con:
table = con.table("table")
res = list(table.scan(filter="PrefixFilter('273810955|')",
row_start='\x0f\x10&R\xca\xdf\x96\xcb\xe2\xad7$\xad9khE\x19\xfd\xaa\x87\xa5\xdd\xf7\x85\x1c\x81ku ^\x92k',
limit=3))
except Exception as e:
pass
end = time.time()
print 'timeout: %d' % (end - start)
此次测试中,我指定了连接池中的超时工夫,冀望的是,连贯超时,及时断开,持续下一次耗时查问。此时,服务端解决 scan 申请的线程状况:
服务端用于解决 scan 申请的 RUNNING 状态的线程持续增长,并消耗大量的 CPU。
7. hbase.regionserver.handler.count
参考大神的博客,以及本人对这个参数的了解,每一个客户端发动的 RPC 申请(读或写),发送给服务端的时候,服务端就会有一个线程池,专门负责解决这些客户端的申请,这个线程池能够保障同一时间点有 30 个线程可运行,残余申请要么阻塞,要么被塞进队列中期待被解决,scan 申请撑满了服务端的线程池,大量的耗时操作,把 CPU 资源耗费殆尽,其余惯例的读写申请也势必大受影响,缓缓集群就完犊子了。
8. 管制 scan 申请占用很小的队列
首先,这个 hbase.regionserver.handler.count
的参数不能被调小,如果太小,集群并发高时,读写延时必高,因为大部分申请都在排队。现实状况是,读和写占用不同的线程池,在解决读申请时,scan 和 get 别离占用不同的线程池,实现线程池资源隔离。如果是我的话,第一反馈可能也会简略、粗略地搞仨线程池,写线程池,get 线程池、scan 线程池。scan 线程池调配很小的外围线程,让其占用很小的资源,限度其有限扩张。然而实在的状况是这样吗?临时,我还没认真钻研源码,HBase 提供了如下参数,能够满足读写资源拆散的需要。以下内容摘自 HBase 官网文档,翻译为谷歌翻译。https://hbase.apache.org/2.1/book.html
hbase.regionserver.handler.count
形容
在 RegionServer 上旋转的 RPC 侦听器实例数。主机将雷同的属性用于主机处理程序的计数。过多的处理程序可能事与愿违。使它成为 CPU 计数的倍数。如果大多数状况下是只读的,则处理程序计数靠近 cpu 计数的成果很好。从两倍的 CPU 计数开始,而后从那里进行调整。默认
30
hbase.ipc.server.callqueue.handler.factor
形容
确定呼叫队列数量的因素。值为 0 示意在所有处理程序之间共享一个队列。值为 1 示意每个处理程序都有本人的队列。默认
0.1
hbase.ipc.server.callqueue.read.ratio
形容
将呼叫队列划分为读写队列。指定的距离(应在 0.0 到 1.0 之间)将乘以呼叫队列的数量。值为 0 示意不拆分呼叫队列,这意味着读取和写入申请都将被推送到同一组队列中。小于 0.5 的值示意读队列少于写队列。值为 0.5 示意将有雷同数量的读取和写入队列。大于 0.5 的值示意将有比写队列更多的读队列。值 1.0 示意除一个队列外的所有队列均用于调度读取申请。示例:给定呼叫队列的总数为 10,读比率为 0 示意:10 个队列将蕴含两个读 / 写申请。read.ratio 为 0.3 示意:3 个队列将仅蕴含读取申请,而 7 个队列将仅蕴含写入申请。read.ratio 为 0.5 示意:5 个队列仅蕴含读取申请,而 5 个队列仅蕴含写入申请。read.ratio 为 0.8 示意:8 个队列将仅蕴含读取申请,而 2 个队列将仅蕴含写入申请。read.ratio 为 1 示意:9 个队列将仅蕴含读取申请,而 1 个队列将仅蕴含写入申请。默认
0
hbase.ipc.server.callqueue.scan.ratio
形容
给定读取呼叫队列的数量(依据呼叫队列总数乘以 callqueue.read.ratio 计算得出),scan.ratio 属性会将读取呼叫队列分为小读取队列和长读取队列。小于 0.5 的值示意长读队列少于短读队列。值为 0.5 示意将有雷同数量的短读和长读队列。大于 0.5 的值示意长读取队列比短读取队列多。值为 0 或 1 示意应用雷同的队列进行获取和扫描。示例:假如读取呼叫队列的总数为 8,则 scan.ratio 为 0 或 1 示意:8 个队列将同时蕴含长读取申请和短读取申请。scan.ratio 为 0.3 示意:2 个队列将仅蕴含长读申请,而 6 个队列将仅蕴含短读申请。scan.ratio 为 0.5 示意:4 个队列将仅蕴含长读申请,而 4 个队列将仅蕴含短读申请。scan.ratio 为 0.8 示意:6 个队列将仅蕴含长读申请,而 2 个队列将仅蕴含短读申请。默认
0
这几个参数的作用官网解释的还挺具体,依照其中的意思,配置肯定比例,就能够达到读写队列,get 和 scan 队列拆散的目标,然而,调配参数后,持续如上测试,发现,并不难管制 RUNNING 的线程的数量,发现没毛用。
这里有一个疑难,队列和我所了解的线程池间接到底是什么关系?是否是一个货色?这个之后须要观其源码,窥其本质。
9. 总结
啰啰嗦嗦总算把定位问题的整个过程记录了下来,其实文字描述的还不算很详尽,只是尽可能还原过后的场景和梳理问题的大体思维流程,省得当前忘记,同时也冀望各位同行能从我这里受到点启发,期间也受到了不少大神的提点,在此也特别感谢各方大佬的帮忙。
Arthas 征文活动炽热进行中
Arthas 官网正在举办征文活动,如果你有:
- 应用 Arthas 排查过的问题
- 对 Arthas 进行源码解读
- 对 Arthas 提出倡议
- 不限,其它与 Arthas 无关的内容
欢送加入征文活动,还有奖品拿哦~ 点击投稿
“阿里巴巴云原生关注微服务、Serverless、容器、Service Mesh 等技术畛域、聚焦云原生风行技术趋势、云原生大规模的落地实际,做最懂云原生开发者的公众号。”