压测：记录Dubbo服务压测及相关问题排查处理

发表于 更新于 分类于 ， Waline：

问题现象

系统A依赖下游的一个dubbo服务B,偶发调用超时（这里说明一下，服务日常平均RT在20ms以内，但是会有偶发超时时间超过1000ms以上，这里超时是因为下游设置熔断超时时间为100ms）。经过公司内部监控工具初步排查，在服务B侧观察到服务比较稳定，95line也稳定在30ms左右，99line也只有70ms左右。但是在服务A端，也就是调用方的的监控上，看调用链上会有远高于接口正常耗时的裸耗时。

监控如下图

问题排查及处理

去社区查看是否有类似问题反馈

去dubbo的issue查找，还真找到有类似反馈，dubbo耗时偶尔无故增加 consumer端打印的耗时明显大于provider耗时 该问题反馈问题现象和我们碰到的一样，已确认是由于tcpNoDelay没设置的问题，升级到2.6.3版本即可解决，原因如下

1.Nagle算法：为减少带宽提高吞吐量，合并小包延时发送，该机制会增加服务延时

2.Dubbo2.6.0版本Netty默认开启该算法，通过设置TCP_NODELAY配置可以禁用Nagle算法

确认了下，公司内部dubbo版本是基于2.6.0的版本改造的，短时间不能直接升级，因为2.6.3调用2.6.0会有不兼容，需要全公司一起升级。那么我们先尝试重写com.alibaba.dubbo.remoting.transport.netty.NettyServer类，设置如下

1
bootstrap.setOption("child.tcpNoDelay", true);

经验证2.6.3对比2.6.0版本主要影响参数为tcpNoDelay，使用设置为true后，公司内部版本表现接近2.6.3 ，TPS有30%左右提升，95线和99线有明显降低。

尝试发布到线上，压测表现有所提升，裸耗时问题有缓解，但是日常还是会有偶发裸耗时问题。

分析是否有JVM的STW

通过cat及公司其它监控以及jdk命令工具查看，GC次数和耗时均正常，且并未触发fullgc

1
2
#每1秒一次显示pid为 1 java 程序的GC情况
jstat -gcutil 1  1000

使用 Arthas定位方法耗时位置

怀疑引入的其它业务方的包里边有耗时的Filter影响，尝试使用trace定位耗时代码位置

1
trace com.alibaba.dubbo.rpc.Filter *   >> &

但是因为服务已经使用了SkyWalking，代码已经被容器的agent增强过，Arthas trace失败

接下来使用profiler 导出cpu火焰图，看能否定位到耗时位置

1
2
profiler start
profiler stop --file /data/result.html

也没有定位到问题。

—–分割线——–

其它团队也碰到类似问题，并且发现不同pod之间表现有差异，长的裸耗时基本集中在某几个固定的pod上，初步怀疑是和pod所在的宿主机有关系，问题交由基础架构团队排查了。