1. Bug 来了
一个平静的周日午后,正悠闲地在公园里遛娃。突然来了一条消息,打开企业微信仔细看了下,竟大吃一惊:客户成功在群内反馈了 Android A/B Testing SDK 的一个 crash,需要紧急解决。
得知问题后我立刻和客户成功进行了语音沟通:了解到客户的应用今天晚上会上线,担心该 crash 带到线上之后会发生井喷,需要我们这边尽快予以修复。得知这个情况之后,一场轰轰烈烈的 Bug 对抗之旅就此拉开序幕。
2. 紧急动员
17 点 09 分
刚刚和客户成功语音沟通完毕,需要立即动员相关的同学处理此问题。
在介绍如何动员之前,先和大家简单说明下 SDK 的发版流程:
- 研发修复 Bug 并完成自测;
- 提供给组员进行 Code Review 并同步影响范围;
- QA 进行测试,如果测试通过则进行发布。
因此,这里要求研发和 QA 同学的深度参与。如果放在工作日,可能会比较简单。但是此时恰逢周日,并且事发突然,客户给予的时间紧迫。
基于此背景,开始兵分两路:
- 第一时间找到 A/B Testing SDK 的项目经理,请他来帮助协调版本发布的相关人员;
- 与此同时,我开始进行问题的定位分析。
3. 独立分析
17 点 52 分
飞奔到家里,打开了客户提供的 crash 堆栈。该堆栈是客户从自己的分析平台里提取出来的,本地无法复现,堆栈如下:
main(1) java.util.UnknownFormatConversionException Conversion = '_' 还原失败(未找到符号表)(404_1_0_2_0_0_0_0_9_0) 解析原始 1 java.util.Formatter$FormatSpecifier.conversion(Formatter.java:2782) 2 java.util.Formatter$FormatSpecifier.<init>(Formatter.java:2812) 3 java.util.Formatter$FormatSpecifierParser.<init>(Formatter.java:2625) 4 java.util.Formatter.parse(Formatter.java:2558) 5 java.util.Formatter. format (Formatter.java:2505) 6 java.util.Formatter. format (Formatter.java:2459) 7 java.lang.String. format (String.java:2870) 8 com.sensorsdata.abtest.a.c.a(SABErrorDispatcher.java:29) 9 com.sensorsdata.abtest.a.d$3.a(SensorsABTestApiRequestHelper.java:236) 10 com.sensorsdata.abtest.a.d$2.onFailure(SensorsABTestApiRequestHelper.java:185) 11 com.sensorsdata.analytics.android.sdk.network.HttpCallback$1.run(HttpCallback.java:46) 12 android.os.Handler.handleCallback(Handler.java:900) 13 android.os.Handler.dispatchMessage(Handler.java:103) 14 android.os.Looper.loop(Looper.java:219) 15 android.app.ActivityThread.main(ActivityThread.java:8387) 16 java.lang.reflect.Method.invoke(Native Method) 17 com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513) 18 com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1055) |
结合上下文分析发现:接口请求失败时,SDK 会打印错误日志。在打印的过程中调用 format 方法导致 UnknownFormatConversionException 异常。
通过上述分析,问题排查范围缩小到:调用 format 方法导致的 crash,并将初步排查结论同步给客户和客户成功。
正在进一步定位为什么会导致 crash 时,突然发现我已经被拉进「紧急处理 Android A/B Testing SDK 崩溃问题」企业微信群。
4. 抽丝剥茧
18 点 04 分
进入到专项问题讨论群后,技术顾问向客户确认了更多的信息,例如 crash 的机型、次数、版本等,进一步完善了问题的周边信息。
此时,群内各位大佬纷纷出谋划策,尝试复现 crash。
思路一:format 方法的第一个参数存在特殊字符 ‘% ‘
String. format ( "where name like % %s" , "Zhang san" ); |
format 方法传入特殊字符,尝试复现,crash 堆栈如下:
Exception in thread "main" java.util.IllegalFormatFlagsException: Flags = ' ' at java.util.Formatter$FormatSpecifier.checkText(Formatter.java:3037) at java.util.Formatter$FormatSpecifier.<init>(Formatter.java:2733) at java.util.Formatter.parse(Formatter.java:2560) at java.util.Formatter. format (Formatter.java:2501) at java.util.Formatter. format (Formatter.java:2455) at java.lang.String. format (String.java:2940) at com.zxwei.cf.lib.MyClass.main(MyClass.java:22) |
可见,这个堆栈和实际的 crash 堆栈不一致。
思路二:format 方法的第一个参数为 null
String. format (null, "Zhang san" ); |
format 方法传入 null,此时 crash 堆栈如下:
Exception in thread "main" java.lang.NullPointerException at java.util.regex.Matcher.getTextLength(Matcher.java:1283) at java.util.regex.Matcher.reset(Matcher.java:309) at java.util.regex.Matcher.<init>(Matcher.java:229) at java.util.regex.Pattern.matcher(Pattern.java:1093) at java.util.Formatter.parse(Formatter.java:2547) at java.util.Formatter. format (Formatter.java:2501) at java.util.Formatter. format (Formatter.java:2455) at java.lang.String. format (String.java:2940) at com.zxwei.cf.lib.MyClass.main(MyClass.java:24) |
比对堆栈信息,发现和实际的 crash 堆栈还是不一致。
思路三:format 方法的第一个参数存在特殊字符 ‘%_’
String. format ( "where name like %_" , "Zhang san" ); |
通过这种方式的模拟,堆栈如下:
Exception in thread "main" java.util.UnknownFormatConversionException: Conversion = '_' at java.util.Formatter.checkText(Formatter.java:2579) at java.util.Formatter.parse(Formatter.java:2565) at java.util.Formatter. format (Formatter.java:2501) at java.util.Formatter. format (Formatter.java:2455) at java.lang.String. format (String.java:2940) at com.zxwei.cf.lib.MyClass.main(MyClass.java:22) |
和实际的 crash 堆栈是一样的,但实际项目中 format 方法的第一个参数是不变的,不可能会出现特殊字符。
思路四:从源码分析产生 UnknownFormatConversionException 异常的原因
private char conversion(String s) { c = s.charAt(0); if (!dt) { if (!Conversion.isValid(c)) throw new UnknownFormatConversionException(String.valueOf(c)); if (Character.isUpperCase(c)) f.add(Flags.UPPERCASE); c = Character.toLowerCase(c); if (Conversion.isText(c)) index = -2; } return c; } |
从源码来看,确实是存在非法字符才会抛出异常,但为什么就是复现不了呢?
5. 妥协还是坚持
18 点 41 分
时间在一点点的流逝,但是问题一直都没有复现。就在大家都一筹莫展之际,我突然灵光一现:由于该问题的出现只是发生在日志打印期间,是否可以绕过 format 方法,通过字符串直接打印日志?这样相当于直接绕过问题,也能进行解决。
很多时候我们都会面临类似的选择:绕过去还是坚持到底?此时,书记给了一个建议:目前是偶现,不着急修复,还是尽量找到根本原因。
不轻易放过一个问题,将问题跟进到底,我们一起选择了坚持。
6. 拨开迷雾
19 点 09 分
这时候项目经理给了一个很关键的假设:连续多次调用 format 方法,并且将引用传递到 format 方法的第一个参数,这样会不会有问题呢?
沿着这个思路,结合项目中的实际代码,确实存在特殊字符且连续调用的场景。基于此假设,我们成功复现出了问题并予以修复。
这一刻让我感到了一个人的力量是有限的,团队的力量是无穷的。
随后 QA 立即远程投入问题验证以及版本发布,在大家的共同努力下于 20 点 40 分顺利交付给客户。
客户拿到新版本后立即集成、自测,并于当天晚上成功上线。
至此,这个问题算是解决完毕。
7. 总结
问题发生在周日,从发现到解决,前后总共 4 个小时不到。
在这短短的 4 个小时内,涉及到项目经理、测试、研发、技术顾问共 7 人。感谢大家的通力合作,使得问题能够在如此短的时间内予以解决。
最后,我想和大家分享的是:
- 于自己而言,遇到问题,要有一颗坚守的心。放弃很容易,但有了一次放弃就会有第二次、第三次。寻求真相的过程必然坎坷,当得到结果的那一刻一切都值得,但求无愧于心;
- 于团队而言,遇到问题,不要一个人去战斗,在必要的时候可以寻求帮助,总会有一群人给我们出谋划策。大家有着同样的目标,相互配合往往可以碰撞出不一样的火花。如果没有大家的帮助,由于个人思路的局限性一定会耗费大量的时间,更别提后续的测试、发版。这次经历也让我更加体会到团队合作的重要性。