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

背景

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

服务基本逻辑

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

问题表象1

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

• 分析：可能是新版本客户端的新增请求导致某逻辑处理时间偏长；
• 方案：抓取大量新版本客户端线上请求对测试环境进行压测；
• 结果：测试环境问题未复现；

问题表象2

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

• 分析：将整体统计细化到机器粒度，发现个别机器响应时间变长的现象特别明显，怀疑某些特例逻辑导致服务性能异常；
• 方案：服务增加debug开关，开启后可抓取特定机器pprof数据生成火焰图；
• 结果：针对出现问题的机器抓取一分钟火焰图观察（如下）

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

问题逻辑

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

问题表象3

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

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

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

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

问题分析

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

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

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

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

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