Hugegraph-Server性能问题分析

上次Hugegraph-Loader的性能问题分析之后, 这次迎来了一个更复杂的分析, 通过Loader进行批量更新导入的时候, 性能逐渐下滑, 直到明显的卡顿问题. 这次尝试从Loader --> Server --> Backend 整体的分析. 大家有好建议和问题也欢迎反馈交流~

0x00. 问题描述

首先说明一下, 这里的导入是“读-改-写”的更新导入, 并不是默认的覆盖写 (后续不再重复说明). 其他同学如果遇到类似”“的问题, 不管是写慢, 还是读慢. 都可以参考分析思路, 但是注意调整对应的观察点(函数).

已有历史数据的情况下, Loader含有更新策略的导入速度先见动图, 肉眼可见的缓慢:

hgLoadSpeed00

补充: 注意如果是简单对比判断是否有卡顿, 可以肉眼这样去看, 但是实际做具体性能分析, 切忌别这样眼睛去测速度…. 比如一次发50条数据, 和一次发500条, 50条从变化上看可能是丝滑顺畅的, 500条有明显卡顿, 但是实际总时间可能500条反而更低…

0x01. 分析思路

虽然问题很明显直观, 但是还是要有个好习惯, 先想清楚大致思路, 再一步步去执行排查, 上来一顿随性操作, 效率巨低.

  1. 先给当前导入缓慢的Loader打火焰图, 先观察是否有明显异常, 如果没有. 对比一下之前的火焰图.
  2. 然后给导入的Server打火焰图, 并观察日志输出是否有异常. (然后搜索Server火焰图里Hbase 字段, 看看耗时)
  3. 如果以上还没有找到问题, 那需要确认具体卡/慢在哪了, 开始使用Arthas
  4. 定位问题根本所在
    • 如果是Server本身, 继续定位慢的函数的每个步骤执行时间
    • 如果是后端(Hbase). 观察后端各项指标, 分析原因

0x02. 慢哪了?

1.loader端

loader端慢, 从我们上次定位性能问题的经验来看, 一般新旧火焰图对比就能很快看出问题, 那来看看带有更新策略的火焰图: (建议查看原图)

hgLoadSpeed00

这里明显有一个在导入的时候很明显的分叉, 出现在readList 的地方, 对比一下之前返回直接Id读取的火焰图 (点此查看原图), 这里还导了边, 当然没什么关系, 可以通过点进去发现readList的占用时间是微乎其微的..

loadMd5FireOld

所以Loader/Client的性能问题目前看并不是导致我们导入性能下降了几十倍的元凶 ,只是存在一个可优化的点.那就继续去Server端寻觅一下.

2. server端

这是一个很通用的问题, 之前我们用Arthas ,其实都很简单, 这次正好是它大显身手的好时机, 因为线上卡顿, 任务执行慢你去侵入的加代码打断点是非常蛋疼的, 一起来看看怎么做:

1. 使用monitor观察类/函数执行概览

首先我们得确定是哪个类执行耗时最多, 从我们只导点来看 ,显然是VertexAPI 这个类(用Arthas一定得至少熟悉是哪阶段出了问题, 再去排查细节), 如果不确定方法, 可以先通配*观察一下:

1
2
3
4
5
6
7
8
# 1.通过sc查找类全名
sc *VertexAPI

# 2.开始全局观察执行耗时(-c指定每次监控的间隔, 默认是60s.)
monitor com.baidu.hugegraph.api.graph.VertexAPI * -c 30

# 补充,如果同时有点边导,或者长时间监控.建议用通配符更方便
monitor com.baidu.hugegraph.api.graph.*API * -c 30

hgServerUpdateDebug00

可以看出当前类里update 方法执行耗时是最多的, 再来单独监控它看看:

hgServerUpdateDebug01

monitor 作用是检测一段时间内(默认1min)的方法执行次数, 通过这个其实我们就可以换算出实际的导入速度, 比如上图中1分钟执行成功100次, 每次如果我们导入的是500条, 那就说明每秒导入速度近似是 100 * 500 / 60 = 833 , 而我们覆盖写的速度可能高达十几万/s, 这个差距就很明显的可以看出来了.

是不是突然觉得有些感人, 平均一次函数执行时间长达10s. 好, 找到一个突破口之后, 再来看看update 函数里面的具体耗时占比, 看看是谁在幕后作祟

2. 使用trace观察方法执行细节

1
2
3
4
5
# -j参数跳过JDK方法计时. -n 设置执行次数上限(默认一直运行)
trace com.baidu.hugegraph.api.graph.VertexAPI update -j -n 3

# 因为可能有些source没有更新策略, 只有写, 为了筛选时间,可以加上参数(>1000ms)
trace com.baidu.hugegraph.api.graph.*API * -j -n 10 '#cost>1000'

hgServerUpdateDebug02

可以看到, update 的耗时集中到了commit() 中, 继续trace (但是这次把范围扩大到*, 以方便Arthas更好的分析调用栈.)

hgServerUpdateDebug04

这样进一步定位到了, 耗时的关键在于 vertices() 这个方法调用, 这个方法对应到代码里(#174 是行号)就是批量查的实现. (更新之前, 先从后端查一批点.), 那下一步就把问题转化到了, 为什么批量读这么慢了.

补充: 至于为什么trace 命令有时候输出一级函数调用, 有时候是多级, 如果想trace多级, 怎么做呢? 详情参考作者解答 (内含原理介绍.推荐!)

然后沿着脉络(这里的图就不一一截了, 基本耗时都在一个方法栈下面), 很快我们就能知道了, 本质就是从Hbase读的时候太慢, 直接跳到最后HbaseSessions 类的get() 方法, 但是这里有多个get 方法, 如果需要trace不能直接传入, 参考作者的同名方法如何trace. 通过ognl表达式来设置. (当然其实没必要了)

3. 到后端去定位

确定了是后端查询返回时间慢, 那就再去看看为什么慢了, 具体每一个查询的耗时是多少. (由于时间关系, 这部分暂时就没细说了.)

不管是Cassandra还是Hbase, 一般也有两种方式可供排查, 一是使用自带日志输出的一些大体的profile信息 (比如打印查询耗时超过XX毫秒的查询), 另一种就是接着使用Arthas , 然后找到调用口重新细节观察, 推荐优先使用第一种 (更快更方便)

然后从Hbase 的日志发现, 500条数据假设合成了一个5k的数据包发给Hbase批量查询, 实际Hbase还是会一条条的去找, 每一次的查询时延根据数据分布大概在5ms ~ 50ms 左右, 平均差不多25ms/条. 这是符合后端存储一般的查询性能的, 如果每条都能在个位数毫秒的延迟返回那多半是内存型后端了… 所以很难说去大幅优化单条的读时延.

那么至此, 这次批量更新的性能问题分析就差不多有了一个结论, 接下来就是看看如何去具体优化了.

0x03. 解决方案

1. Loader端

  • 调参: 这里需要修改三个参数
    1. 导入线程数( --num-threads ) : 默认是OS可用逻辑核心数(比如20), 根据Server和后端负荷上限, 可能设置为80~1x0 ? (最大值待确定..)
    2. Client初始化的HTTP连接池的最大连接数
    3. Client初始化的HTTP连接池的最大连接数/Server (默认40)

2. Server端

  • 调参: 需要调整两个参数

    1. Server可工作的线程数,: 默认近似OS逻辑核2, 根据实际后端可承载最大值, 调为比如*4~6倍** (最大待确定)
    2. 批量导入的时候允许使用线程最大比例 : 默认50% --> 95% (100个线程可用95个用来批量导入)
  • 修改默认线程发送模型:

    当前的模型是读写在一个线程内,先读后写, 阻塞模式, 这样如果耗时绝大部分都在读上面, 利用率就明显偏低. 考虑可以把读写的线程分开(两个队列), 假设总共100个线程, 90个专门给读, 10个给写. 以提高线程的使用效率.

3. Backend端

虽然单条读时延很难有质的优化, 但是大量导入数据之后本身 LSM 结构下的存储, 一般也多少能通过手动Compaction 来进行优化, 大概做完几次, 能提高50%左右的读效率.

不过要特别注意的是, 如果是相似的测试数据, 后端可能会存在大量缓存, 导致测试结果不准确. (所以应该尽量在同类数据的不同日期或中等数量下导入.)

4. 测试方案

为了验证假设是否合理, 制定一下对比方案: (Server最大线程占用比98%)

次数/对比项 Loader线程数 Client最大连接数(两个) Server线程数 Hbase最大连接数 速度/效率
第一次 40 50 80 64 7900/s
第二次 80 100 200 218 9300/s
第三次 80 100 200 218 8500/s

注意 : 为了确保线程都成功开启并都在干活, 建议从两个方面验证一下:

  1. Server通过jstack 查询grizzly-http-server 的数量, (比如: 0~100个) .然后看看是不是都在正常工作(连接后端. 而不是在线程池等待,)

  2. 通过netstat 或类似网络命令, 查看实际建立的连接数 (Loader和Server建议都看看, 以免连接数就被限制了…)

    1
    2
    # 替换实际pid, loader和server建议都看看,实际数目是否符合预期
    netstat -anpl |grep pid |grep ESTABLISHED | wc -l

然后对比的方式, 就使用Arthas的monitor 来对比, 1分钟执行的方法次数, 这样不管是每次导50条, 还是500条, 开启多少线程, 最后的总量是可以很直观的计算出来的. (测试性能的时候一定要注意控制变量, 找到一个通用的参考标准)

中间省略大量的实际测试图和记录, 最后发现当线程数超过80左右, 导入速度已经明显停滞不增, 但是Server负载和后端负载也还是不高, 于是去后端查看, 发现此时机器的磁盘IO (多块SATA盘)已经全部打满, 虽然读的请求很小, 但是次数偏多(350/s次读请求) ,而机械磁盘因为寻道结构设计, 天生就不适合做这种操作….

补充:

上面说的是都是带更新策略的导入场景, 顺便也测了下纯写的速度. 我们[发现](#0x04. 结论)提高Loader和Server线程数, 只要后端写没有到瓶颈, 哪怕是Hbase也可以有非常高的写入速度 (高达40万/s +, 可能还能更高, 之后待补).

0x04. 结论

这次的性能测试虽然写的内容比较少, 但是实际中间因为忽视了一些潜在问题, 反复走了不少弯路, 浪费了不少时间(比如开始没发现Loader到Server有一个HTTP连接池最大是40, 从而得到了一系列错误结论… 后面Hbsae的最大连接数汲取教训倒是较快发现了.)

最后得出的几个方案是:

  1. (硬件)大批量的随机读会直接把普通SATA磁盘的最大请求次数很快打满(大概单盘200300次), 导致IO成为瓶颈, 此时最好是更换PCIe接口的SSD, IOPS是普通HDD(机械盘)的**几十几百倍**. 当然也可以增多HDD磁盘数量, 或者组RAID.
  2. (软件)如果存储偏大, 全SSD成本过高的情况下, 则应尽量让已导入的数据进入后端缓存中 (或考虑redis), 一次性把某一个顶点(比如Person)的所有数据更新完, 再开始导入下一类顶点, 这样缓存命中率实测会高很多, 大量减少随机读的次数, 实测速度可能快10~20倍. 如下顺序所示: (采取第一个策略)
    • Person1 –> Person2 –> Person3 –> ….. –> Personx (√)
    • Person1 –> Doge1 –> Cat1 –> ….. Person2 –> Doge2 –> Cat2 (X)
  3. (软件) 至于0x03中提出的分拆读写的线程队列是否更有效, 也只能等有SSD能把IO瓶颈的问题解决才能再确定了….(期待大家反馈:)
  4. (软件) 优化Client反序列化Json读取List的使用方式, 从火焰图看最大能也有30%左右性能提升 (待续…)

通过这两次在Loader和Server的性能分析, 相信对以后遇到各种性能上的问题都有了一个比较好的通用检测方法, 再遇到类似改了代码后速度变慢了, 用户提问运行慢的问题, 也可以参考快速定位一下到底慢哪了. 还是那句话 “不要用眼睛定位性能问题, 而是性能测试”.

几个优化方案, 之后优化后继续补充, 待续….


参考资料:

  1. HugeGraph官方配置文档
  2. Arthas作者相关issue