核心内容摘要
ãADN-622ã
1 背景2 验证与分析
1 准备工作
2 验证
3 问题分析
4 排查
5 原因3 解决方案
1 框架优化-弹性超时4
总结1 背景一个春暖花开的午后客服技术部佩姐P找过来向我们反馈一个问题如下是我们的对话P云杰我们最近在治理服务质量有个接口的成功率达不到公司标准5个9。
我赞你们也开始质量治理了详细说说。
P我们sccis有个重要的lookupWarehouseIdRandom接口先查询缓存未命中的再从数据库查并回写到缓存平均执行耗时只有
5ms。
现在scoms在调它超时时间配的还是100ms结果发现每天还有500多个超时成功率不到5个9达不到公司标准。
你们框架是不是有问题啊帮忙看看 我不至于吧平均执行耗时
5ms在调用方超时时间配100ms60多倍的情况下竟然还有这么多超时 P真的不信你看看 我看看就看看如下开始本篇的研究之旅。
2 验证与分析
1 准备工作在开始验证之前先简要介绍下转转RPC框架SCF的调用过程如下图所示序列化SCF接收到调用方的请求做负载均衡、序列化等发送SCF将序列化后的二进制流通过网络发送给服务方结点反序列化服务方结点接收到数据后将数据交给SCF做反序列化、排队等执行SCF将请求交由服务方的实现方法进行处理序列化SCF将服务方的处理结果序列化为二进制数据流发回将数据发回给调用方反序列化调用方SCF收到请求后将二进制数据反序列化为对象交由调用方代码使得调用方看起来跟本地方法调用一样。
如上是一次完整的RPC调用链路。
2 验证通过监控我们发现接口的平均执行耗时确实在
5ms左右如下图所示但调用方scoms在超时时间为100ms的情况下确实仍然有很多请求超时太让人震惊了
3 问题分析通过如上的RPC调用过程链路示意我们可以看出任意一个子过程都可能会发生抖动造成超时。
但我们可以从整体上把链路分为框架和业务两个部分分界点如图所示框架指底层的网络和SCF耗时属于客观原因包括图中的
1、
2、
3、
5、
7业务单纯指业务服务的执行4属于主观原因。
因为框架耗时复杂多变不好统计我们可以统计业务的执行耗时分布以此来判断问题出在框架上还是出在业务上。
如果业务的执行耗时分布都非常低那就说明超时花在了框架上如果业务的执行耗时分布都有很多高耗时的那就说明超时花在了业务逻辑上。
正好服务方的接口有耗时分布监控通过监控我们发现绝大部分情况都在5ms内处理完成但仍有314个请求处理时间直接超过了100ms耗时分布这个发现也让我们大吃一惊平均执行耗时
5ms的接口竟然还会有这么多请求执行耗时越过100ms那么这些时间都花在哪里了呢
4 排查目前的监控都是接口的整体执行耗时我们需要深入接口内部看看时间都花在哪里了。
我们对接口分为如下几个部分并分段监控起来。
监控结果如下所示从结果可以看到I/O操作容易抖动出现较多次100ms最简单的CPU操作虽然没有那么多100ms但也有不少20ms左右的情况而且都是从1ms突变到20ms而不是渐变。
5 原因原来我们是被
5ms给平均了什么原因会导致这种长尾效应呢情况可能有很多GC极度怀疑、CPU时间片分配等。
如下是sccis的GC监控为此我们也对比了转转商品服务zzproduct的getProductById()接口发现也有同样的情况getProductById()耗时分布3 解决方案至此我们看到业务接口平均执行耗时虽然仅有
5ms但仍会出现不少超过100ms的长尾效应当然框架也会出现。
其原因有多种GC极有可能、CPU时间片分配、网络抖动等等。
而这也确实刷新了我们所有人的认知。
反过来想如果业务接口要达到公司要求的5个9要求该怎么办呢其实很简单我们可以参照调用方的TP9999来设置超时时间。
如下图scoms调用该接口的TP99999是123ms而业务把超时时间配置成了100ms那肯定达不到5个9的标准了。
要么把超时时间改为123ms简单直接要么优化业务逻辑目测很难因为平均执行耗时只有
5ms或JVM调优很有希望。
1 框架优化-弹性超时基于本文分析RPC框架也可以针对这种长尾效应做一定优化不改变超时时间100ms配置情况下允许一段时间可配一些量可配的请求在200ms可配时间内返回既提高了服务质量又不太影响用户体验我们称之为弹性超时方案。
3.
1 效果如下图所示我们在服务管理平台支持按服务函数设置弹性超时这里我们将上文zzscoms调zzsccis的IInventoryWrapCacheFacade.lookupWarehouseIdRandom(List)函数配置成每40秒允许15个请求的超时时间延长至1300毫秒。
弹性超时配置通过配置弹性超时我们看到这种偶发性的超时基本被容忍消灭掉了如下图所示
3.
2 适用场景弹性虽好可不要贪杯它更多适用于一些偶发性超时场景比如网络抖动、GC、CPU抖动、冷启动等如果是大面积的超时还是需要深入分析治理。
4
总结本文深入分析了平均耗时仅有
5ms的接口也会出现大量100ms的前因后果并在框架层面给出了弹性超时的解决方案。
这也刷新了我们的认知由于GC、CPU时间片等原因一些看起来很简单的操作如i也会出现偶发性长耗时。