记一次服务问题的定位过程

背景

最近经常发现一个线上服务的响应时间会变长,分析线上metrics统计,发现偶尔会有一两台机器问题比较严重,经过多番追查,确定了问题,并修复了,在这儿回顾一下这个过程;

服务基本逻辑

记一次服务问题的追踪过程

客户端不同类别请求,由服务端的不同逻辑处理,每种逻辑处理耗时不同;服务端启动时需加载多组配置数据,供后续不同逻辑使用;

问题表象1

晚高峰时,根据metrics统计,服务整体响应时间变长;但使用测试环境压测未见异常;

分析:可能是新版本客户端的新增请求导致某逻辑处理时间偏长;

方案:抓取大量新版本客户端线上请求对测试环境进行压测;

结果:测试环境问题未复现;

问题表象2

第二天早上,流量低谷时段,又出现服务整体响应时间变长的问题;

分析:将整体统计细化到机器粒度,发现个别机器响应时间变长的现象特别明显,怀疑某些特例逻辑导致服务性能异常;

方案:服务增加debug开关,开启后可抓取特定机器pprof数据生成火焰图;

结果:针对出现问题的机器抓取一分钟火焰图观察(如下)

记一次服务问题的追踪过程2

可见Ahocorasick.Match函数耗时特别长;追查代码后为解决线上风险,暂时屏蔽了用到此函数的新增逻辑;

问题逻辑

用到此函数的新增需求大概如下:服务启动时加载一组词表,当用户请求命中词表中的词时,进行新增逻辑;此处耗时超长的Ahocorasick.Match 函数就是上述需求中对词表进行匹配的函数,查了一下,使用的是第三方的AC自动机库,且这个库在其它功能处也有使用;

问题表象3

测试环境无法复现,线上环境每隔一段时间就会有个别机器出现;

经分析测试环境与线上环境的配置是有差异的:为测试此功能,在测试环境配置中,增加了一些应命中匹配的词表,故在测试环境中按词表中的词条执行测试用例,可以命中新增逻辑;但线上环境配置的词表中并未增加任何词条;如下图:

记一次服务问题的追踪过程3

然后分析函数Ahocorasick.Match逻辑,发现一处bug:当匹配列表没有insert任何词条 且 被匹配内容是ascii码=1的字符时,函数下图处会死循环

记一次服务问题的追踪过程4

之后,构造了相同的条件,在测试环境中复现此问题;由于之前用到这个自动机库函数的其它需求,的匹配列表中均有内容,所以线上一直未发现问题;

问题分析

总结一下由此问题想到的几点测试需要注意的地方:

1、针对第三方库,要持怀疑态度,上线前至少要对主要功能使用到的函数做单元测试

2、理想的认为匹配列表中不insert词条,即可以暂时屏蔽线上的功能;实际上是漏掉了一个影响因素(ac自动机词表为空时,执行match)

3、线上服务要建立应急机制,可能因为某一个影响因素的改变,导致线上稳定运行的服务或函数无法正常运行;

4、github上的开源项目尽可能用star多的。

源自公众号 搜狗测试



留言