人在江湖飘,哪能不挨刀。
我挨了重重一bug。严格来讲这可能是我职业生涯以来的首个悲惨经历,因为凭我的知识储备和经验,基本上任何可重现的bug都是可解的。然而这个bug却困扰了我三个月之久,它具有以下生理特征:
- 后台日志能统计到异常,偶发、低频
- 报异常的用户设备不具有规律性,什么手机都有
- 我们自己无法复现,任何设备、任何环境都没复现
- 打电话回访报异常的用户,确实存在问题
- 客服未接到用户主动反馈这个异常
此bug并不是js报错,而是一个业务逻辑的错误。表现是,用户提交的数据莫名缺失。场景是以下这个界面
当用户填满所有的空之后,提交按钮变为可用状态,数据放进一个数组中提交上来。后台有报错日志显示,用户提交上来的有些是空数组,有些是数组中缺了几项。
问题在于,提交前是有校验的,用户不可能提交上来这种未通过校验的数据。并且还是偶发的啊,如果是逻辑写错了,那应该全部会报错,我们在测试的时候肯定会发现。
最棘手的地方是,我们压根没重现过这个情况,找各种同事、各种手机、各种胡乱操作,一次都没重现出来。这就给调试带来很大的麻烦,只能是猜测哪里可能出问题,然后去验证。但是根本没法去验证啊。。。重现不了,又如何判断是成功fix了。
看来能验证的手段就只剩一个:线上日志。猜问题、上线、看日志。
这是一个痛苦的过程。界面虽然简单,这却是一个庞杂的项目。因为题型众多,抽离了很多组件,为了公用和灵活扩展,组件嵌套深度有五层之多。其架构复杂程度在我的职业生涯中也能排TOP3.
拿题干的渲染来说,就有:公式图片转LaTeX、mathjax渲染公式、渲染公式上的空、给空编号、模拟光标、自动focus空、动态计算字体大小等诸多流程。而且下方那个键盘还是我们H5模拟的,并不是系统键盘。更别提还有校验逻辑、判分逻辑。
前n次尝试
看距离上一版有哪些改动,抹去有嫌疑的改动,看日志是否正常。尴尬的是,这是一次重大重构,改动的地方还特别多。于是一场盲人摸象式的远程debug行动开始了。
一次又一次的上线、观察日志、下线。不断排除了一些相关的功能,始终未能诊断到问题所在。甚至连我很确信的地方都尝试了,还是找不到问题。前前后后尝试了二十多次吧,改到我都怀疑人生了。领导看了这些上线记录都怒了,说你这上上下下的搞鸡毛呢。我也很崩溃啊。
看来用这个盲人摸象手段是搞不定了,我意识到了情况的严重性,暗暗感觉这可能不是轻易能解决的,吕某一定使出毕生所学,为民除害。
第n+1次尝试
既然有那么多的用户日志,我们自己为何重现不了?这是我一直纠结的。于是再次进行疯狂测试。
皇天不负有心人,我竟然真的给重现出来了!操作是这样的:填好空,两个手指同时按下提交按钮和删除按钮。这样的话既通过了校验,又能在提交之前把数据给删了。
发现这个骚操作的时候我是很兴奋的,但是会有那么多用户这么操作吗?显然不太可能。此时我又想到,提交按钮和删除按钮是挨着的,会不会是用户按提交的时候误触了删除键。这还算比较合理,毕竟用户是小学生嘛,操作不一定那么精准的。
我兴奋不已的进行验证。在删除键和提交键之间加了“下一空”按钮(通过配置),这样用户保证不会误触了。
上线,日志依旧。我摔啊,看来并不是误触的事。
第n+2次尝试
随着bug拖的时间越来越长,我的心态也有点焦躁。但思路还是聚焦在删除按钮上,毕竟这是好不容易发现能重现的。
如何能够既点提交又点删除呢?这时候我想到了点击穿透(键盘为了响应快,使用了touchstart事件)。因为在点完提交的时候,模拟键盘会收起来,而收起的过程中删除按钮会经过提交按钮的位置。根据点击穿透的原理,如果此时派发的click事件作用到了删除按钮上,那岂不是就算点到了?
我都有点佩服我的想象力了,黔驴技穷了啊,试吧。避免点击穿透有两种方式,阻止click事件的默认动作,或者是让元素收起的时间延迟。我选了后者。
上线,日志依旧。我吐血。后来一想,删除按钮根本都没监听click事件啊,哪来的穿透。真是病急乱投医了。
第n+3次尝试
扫代码,发现一个很重的疑点。答案是个数组,是引用类型。由于复杂的组件关系,这个引用类型的数据可以被多个组件访问到。
使用可变数据的时候有个隐患,它可能在你不知道的地方被修改。代码是vue写的,有些组件中含有watch,搞不好是意外进了哪里的watch,在点完提交的时候也会把数据给更改了。
这个猜测我觉得是合理的,在开发阶段我就曾因为未使用immutable数据而隐隐担心过。好了,快速验证吧。在点完提交按钮的时候,我把答案数据给克隆了一份,然后再进行判分和提交的操作。这下就不担心已经拿到的数据被篡改了。
上线,日志依旧。继续吐血。
不过这次也缩小了嫌疑范围,看来数据不是在点完提交的时候被篡改了,而是提交上来的就有问题。匪夷所思的是,用户是如何绕过校验把数据提交上来的呢?难不成是我的校验函数有问题,这个地方把数据给改了?扫了一遍代码,无果。
第n+4次尝试
此时聚焦到了用户在填写答案的时候发生了什么。我像侦探一样用放大镜一遍遍看代码,然而好多天的追踪,并没有找到什么有用线索。
直到有一天,那天阳光明媚天空飘着朵朵白云,感觉有什么好事要发生。QA在反馈群里发了一张截图,说公式解析的那个点点点一直不消失(正在解析的状态),而且空里也输不进内容去。如下图:
我敏感的神经顿时嗅到了一丝线索。题干使用了mathjax来解析公式,而mathjax在解析的过程中会按需加载一些字体文件,而且还会扫描页面节点,并生成大量的DOM节点。这对浏览器来说是个压力不小的事情,更何况是移动端。
我马上再扫描公式处理的代码,由于有些空会在公式上出现,所以代码是在等公式渲染完后统一给空编序号,然后进行自动focus,而且自动focus的时候还会首先给答案赋值。天呐,问题该不会出现在这里吧!公式的渲染过程可能有延时,用户可能在这个时间进行点什么操作!
首先这符合偶发这个事实,因为公式解析中出现抖动网络延迟什么的也是偶然现象。再者公司的网络快,用户的网络可能慢,这也符合我们一直未重现的事实。感觉这次很靠谱了!很多侦探电视都是这么演的啊,主人公通过别人无意的一句话联想到了线索,然后案件破解,真相大白!对对对,就是这个感觉!
赶快在代码层面做优化,尽可能早地处理没有公式的空,有公式的地方也确保执行完后用户才能输入。
优化完毕,回归测试,万事俱备,只等线上验证,一锤定音!
结果......日志还有啊!啊噗!,电视里都是骗人的啊!
等等!日志虽然还有,但好像少了耶!难道这次的优化是有作用的?虽然从理论上能解释一些作用,但还存在的日志又表示什么呢?难道造成丢答案的原因不止一个?
第n+5次尝试
时间一天天过去,我还是没找到什么有力线索。中陆续有一些猜测,打了一些日志点后还是无果。看着QA同事紧缩的眉头,领导关切的询问,我也越发焦虑了起来。因为我这是一个公共组件库,有其他项目在等着使用,如果我的bug解决不了,将影响其他项目的进度。
又是阳光明媚的一天,天空飘着朵朵白云。我无意跟另一位后端同事聊到了这个话题,他随口一说:应该是超时自动提交的吧。
什么?什么!自动提交?!我突然像被闪电击中。因为我写的这是个公共组件,同时也对外暴漏了一些API,比如提交答案就是其中一个。我提供的是答题界面的组件,但是别人项目中有倒计时的场景,超时后会调用我的提交API,把用户答案提交上去。
如果超时的时候,用户什么也没填,那岂不是把空答案给提交上去了!!!根本没有校验函数什么事,是别人调API提交的啊。
我哭了。难怪没用户反馈呢,时间到了自动提交空答案,他们没理由反馈啊。难怪我们自己没重现呢,一直沉浸在怎么乱点出来。就算QA同学看到了超时提交的时候,也无法意识此时是空答案。
没错,真相就是它了,修改相关逻辑后上线,果然报错日志没了。困扰我三个月的bug终于解决了!我闭上眼睛,心里默默放了一把鞭炮。
总结
前前后后三个月时间,总算是找到了问题所在。其实第n+4次是解决了一些问题的,最后一次是彻底解决,我用实际行动证明了,真相不止一个。而这件沸沸扬扬的丢答案bug事件,也给了我很多启示。
做重构的时候要格外小心逻辑更改,重构后一定要跑通所有case。
排查问题的方式,这期间我使用了各种对照试验,各种源码级别的排查
使用vue做复杂项目的时候要格外注意组件的嵌套层数,少写watch,避免程序执行顺序的混乱
设计对外API时,要考虑健壮性,不光考虑传入参数的不稳定,还要考虑当前上下文的不稳定。