案例分享:如何用放大镜暴露问题

这是个十几年前的故事,它跟你所用的工具、语言、应用领域关系不大,纯粹是思维方法的事。

我当时在做手机操作系统自带的短信应用,出差到总部的时候,看到团队里面讨论性能问题的邮件:

甲测试写入短信内容的时候觉得有点慢,乙作为开发要求提供证据,因为他自己调用API得到的时延是50毫秒左右,还是重复了200次之后的平均值。甲说我掐表看见的是1秒多界面才提示写完。于是双方各执一词,还要怀疑上界面部分的代码,没有证据人家当然不搭话。各方扰攘了一个星期都没有结论。

总部的组长私下问我能不能帮忙看看。我决定换个方法试试。

这个API是往底层的轻量数据库接口插入数据库表的一行,表示一条新短信,相应的也有查询和删除。现在的焦点是模拟器触发了一条短信从通信接口收到之后写入数据库,或者是编写一条新短信写入数据库,这个场景性能有无问题。既然开发已经单元测试过至少200次调用平均延迟可以接受,那么显然再重复在“干净”的表上面调用插入API不会有新发现。那就多插入一些知道数据库不再“干净”再看看好了。

我的做法不是用模拟器触发,而是直接反复调用API填入不太长的短信内容。从1000次开始,时延65.3秒;重设数据库内容,2000次,时延160.4秒;再来一轮4000次,441.2秒。

唔有点不对,这时延总和不是应该大致等于单次调用的时延50毫秒乘以调用次数吗?而且怎么误差随着重复次数增长变得越来越大呢?排除了测试代码带来的额外开销之后,为了找出误差的规律,我变换了测试时延的办法。

之前的测试伪代码是这样的

// reset DB content
DWORD start = GetTickCount();
int count = 1000;
for (int i = 0; i < count; ++i)
{
    // call DB insert API
}
DWORD end = GetTickCount();
printf("%d\n", end - start);

新的测试伪代码是这样的

// reset DB content
int checkpoint = 100;
int count = 1000;
int i = 0;

while (i < count)
{
    DWORD start = GetTickCount();
    for (int j = 0; j < checkpoint; ++j, ++i)
    {
        // call DB write API
    }
    DWORD end = GetTickCount();
    printf("checkpoint %d - %d\n", i, end - start);
}

这一跑下来是这个结果:

阶段时延(秒)
1-1005.15
101-2005.45
201-3005.76
301-4006.02
401-5006.16

每次打印的时延表示内层循环里面只调用了checkpoint那么多次API,而且每次调用的次数都是100次,显然不断增长的时延不是随机因素或者GetTickCount返回值精度不足的问题。虽然按照文档,100毫秒之内的部分精度不靠谱,但是如果这个表里面所有的时延都随着阶段增长而增长,那就可以排除这个精度的因素了。

所以我更换count和checkpoint的值重试了好几遍,证实了这个结论,哪怕考虑了GetTickCount返回值在100毫秒内的精度不可信,时延都随着阶段增长而增长。看起来每写入固定数量的短信项,总时延就会稳定的增长一个常数值,而且这个常数值正比于写入的固定数量。

这么看很像是插入行的时候没有搞好index,当然以我在这件事里面的角色当时没必要找到根本原因,而且刨完代码去跟开发扯皮,人家不变应万变一句你不熟代码我做了很久了就能让你歇菜。所以只需要证明给开发说这是个足够严重的问题就能让对方乖乖去修理,接下来我的工作就是预测什么情况下写入时延会变得很坏,因为如果不是太严重,对方可能压根不理会,把bug标记为低优先级就扔一边去了。

既然用不同次数组合重试了好几遍,这个表的数据就有很多份,我拿到Excel里面分别画出线性图并让它回归预测,不出所料,都是斜率一致的直线。那就好办了,时延是关于写入次数的一阶线性函数,这是个等差数列。

假定时延Ti = a + b * i,i表示写入第i条短信,a和b是常数。我的目标是解出b。

每100次的总时延按等差数列的求和,头加尾乘以个数除以2:

\sum_{n}^{n+100}Ti= (a + b * n + a + b * (n + 100)) * 100 / 2 = 50 * (2 * a + 2 * b * n + 100 * b)

任意两个不同阶段的总时延相减,比如对于n1和n2阶段的差值,显然2 * a和100 * b的部分会被消除,只剩下2 * b * n * 50。以n1=100,n2=200为例,差值等于

2 * b * 50 * (n2 - n1) = 2 * b * 50 * 100 = 5.45 - 5.15 = 0.30

于是得到b = 30 微秒。我又拿着其他组合分别算了很多次b值,其平均值为30 微秒。

再代入验算一下a值,都在50 毫秒左右,与开发的报告相符。所以a和b值是可信的。

这么说,每写入一条短信,API都比上一条慢30微秒。开发做的200次重复才慢6毫秒,跟基数50毫秒平均一下变成53毫秒肯定看不出来,说不定还认为是GetTickCount精度的问题。但是当i等于10万,也就是数据库里面已经有10万条短信的时候,每次收到或者编写下一条短信仅仅在API上的时延就达到3秒钟,足够让用户抓狂了。

这个邮件发出去之后,总部经理说,这个影响有点大喔,乙你要不要去看看。乙说好我去看看,但是3秒时延这个事是真的吗?你猜的吧,我不知道是不是真的那么严重。

行,我改一下测试代码,重复10万次之后再单独打印50次写入的每一个时延,结果都在3秒以上。

这下没话说了,乙乖乖去修index的bug,改完之后再跑一次,上面那个表的每个时延稳定在5秒上下,10万次的测试也证实了之后单独写入的每个时延都是50毫秒。

总部经理跟我们几个出差的同事social的饭局上问起,你邮件里面那公式叫什么名字,等差数列英文怎么说我那时还不会,总部一个华人同事翻译了(arithmetic sequence),老外说,嚓,那是我念大学的时候才第一次碰到。后来我知道,老美到念预科或者大一的时候才恶补数列、解析几何、三角函数什么的,不然高等代数没法教。想起我们初中就学这个,有点汗。现在老美注重STEM/STEAM了,不知道会不会有所改善。

当时我又问,那甲的测试环境里面有多少短信,说是3万左右,他一直没有清理,呵呵,果不其然。

这个案例里面,新的测试代码里面的内层循环就是个放大镜,用不同组合多看几次会很有帮助,不妨在其他地方试试。

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值