图1 dapper
图2 商品中心的调用和被调用情况Step 2.关注接口响应时长工程接口的响应时长被我们细分为不同区间:
图3 工程接口被调用时的响应时长统计Step 3.看 时间-次数 曲线点击对应的"图表"链接,我们进入服务调用统计图表页面。我们随后选择"1-5s"Tab页,如下图所示,可以看到商品中心 183 节点在6月24日里,接口响应时间在 1秒~5秒 之间的情况:
图4 调用统计图表看到这里,我们只是知道某个时间点,商品中心有点不正常,但还不知道是哪一个接口不正常。Step 4.看 时间-次数 曲线点击上图中的那个红点,从而进入 10点30~10点35 之间接口响应时间在 1秒~5秒 之间的分接口曲线图:
图5 分接口曲线图这样,我们发现,原来全是 sortGoods 这个方法引发的。但这还不够。我们还是不知道为什么慢。Step 5.看散点图点上图中的那个蓝点,进入 10点30 左右的真实调用散点图,图上的每一个点都代表一个真实的调用:
图6 散点图从上图可以看出,sortGoods 接口方法其实大多数响应时间在 500毫秒以下,最大响应时间也不超过 1.5秒。我们选中响应时间最大的那个点,点击一下。Step 6.看瀑布图点响应时间最大的那个点,进入 10点30 左右、sortGoods 方法响应时间为 1.347 秒的真实调用链的瀑布图:
图7 瀑布图瀑布图一般都很长。它可视化地绘制了每一层调用,包括进程内调用,包括跨进程调用,包括对缓存、对数据库的请求。每一层调用,都可以看到具体参数,如 HostIP、RequestIP、输入参数、SQL语句(假如访问了DB的话)、对缓存是GET还是SET,如果有异常抛出,还能看到堆栈信息。假如是对 memcached 批量获取,还可以看到具体的 keys 数组,如下图所示:
图8 keys也可以展示最终,我们找到了 sortGoods 这次调用花了1秒多的原因:
图9 有一个 update 接口操作花了 540 毫秒那么接下来分析这个方法的代码即可。如上所示,经过刘奎等同学的努力,天机与鹰眼联手,在没有部门经理、研发经理、工程师的帮助下,我自己就能通过天机系统从宏观看到微观,并最终明确某个性能瓶颈的 Root Cause(当然还不够接触本质)。这还不够。还有其他的调用路径分析和调用去向分析场景。以后再讲。-EOF-辅助阅读:#研发解决方案介绍#Tracing(鹰眼)#研发解决方案介绍#基于StatsD+Graphite的智能监控解决方案延伸阅读:窝窝研发哲学新闻热点
疑难解答