追查闪退的六个日与夜
老Y是一名iOS开发，近日在工作遇到一个闪退，临近提交App Store时才发现，虽然紧急修复后顺利提交审核，但由于问题暴露的时间过晚，因此引起了众多额外的关注。问题本身理应很容易发现，但为什么临近审核才反馈，老Y为了分析该问题，花了六天的时间才找到原因。在一个具有数百个模块的大型App中，如何根据各种蛛丝马迹找出问题根因？本文记录了老Y追查该问题的六个日与夜。
闪退不可怕，开发与测试的过程都应该能够发现，这个问题本身没有特别值得记录的地方。可怕的是为什么经过这么多轮测试却没能发现闪退，开发联调阶段也没能发现闪退，正是为了解释这些才有了本文。
如果你的App中也使用了PLCrashReporter，或者你对老Y追寻六天的过程感兴趣，不妨看完这个故事。如果想直接看结论，可跳至后记。
目录
第0天 阻审
晚上11点，老Y刚洗完澡准备睡觉之际，看了一眼手机，发现被拉进一个群，群名称：”xxx crash”，心想：“我去，今晚就要提交App Store审核，该不会这个点出现问题了吧。”老Y点进去一看消息，不幸言中。业务发现一个必现的闪退，其它同学已经可以在本地复现，正在分析问题产生的原因，PM在等着结论，决定何时提交审核。
这样的情形对于老Y来说已经不会再大惊小怪，多年的互联网从业经历让老Y养成了电脑随时带在身边的习惯。12月的深圳此时终于有了点冬天的样子，夜里气温很低。于是老Y披上外套，拿着电脑来到客厅。
打开电脑后，老Y首先看了看群里的上下文，目前了解到的情况是：业务每天都有进行测试，但之前一直未发现问题。而今晚却在另外一个安装包中发现该问题是必现的。“之前的安装包与今晚测试的安装包有什么不同？”，老Y开始与反馈该问题的同学一起分析。刚开始推断可能前几天有几个模块进过一次集成，但很快这个猜想就被推翻。测试发现集成前后的安装包都会出现该闪退。
测试在开发的询问下，不断的提供越来越多的信息，完整的问题逐渐显现出来。终于，在午夜钟声敲响之际，定位到是debug包与release包的问题。之前测试使用的都是debug包在测试，而今晚切换到了release包。“又是release与debug的问题，一定是有什么变量没有初始化导致的，release下未初始变量可能是个随机值”，凭借之前踩过的很多坑，老Y信心满满的猜想。
而此时，负责该模块的同学老J本地调试也发现了该问题，准确的定位到闪退处。从Xcode的debug窗口中可以明显的看到一个空的数组指针，访问该数组时出现EXC_BAD_ACCESS闪退。那么问题看起来很容易解释，只需要查出为什么该数组是空指针就能够解决问题，笑容在老Y与老J脸上浮现出来。
可是，他们高兴的太早。这个数组指针在一个函数中赋值，但该函数没有异常路径，数组一定不会为空。“这就奇怪了，这个函数出了什么问题？”，老Y与屏幕另一端的老J都感到不解。为了弄清楚函数执行时发生了什么事，老J在该函数中设置了一个断点，打算单步调试该函数，这是最直接的方式。
没想到奇怪的一幕再次发生，老J刚刚设置的断点竟然不生效。老J不敢相信自己的眼睛，于是又在函数调用前与调用后又加了断点，再次运行。函数前的断点正常停下，“不错，证明代码走到了这里”，老J开始紧张起来，小心的点了单步执行，没想到程序直接到了函数调用之后的断点，函数中设置的断点依然没有停下来。
“这不可能啊，同一个代码库中的代码，函数前后的断点都能够停下，为什么这个函数就是进不去？”他们大为不解。此时，老Y说，用lldb命令试试吧。于是老J再次调试，在调试控制台中输入了breakpoint set -name xxx，再次运行，他们紧张的期待着运行的结果。
老Y说：有时候在Xcode的源代码中直接添加断点无法进入时，可以通过lldb或者添加符号断点的方式来设置断点
终于，如他们所愿，程序在函数入口的断点处停了下来，然而展现在断点处的竟然是汇编。“源文件明明就在工程里面，为什么会进到汇编？”，老J说。“clean下试试。”于是老J将整个工程清理了一遍，为以防万一，又手动删除了Derived Data，然后再次尝试。可结果依然如此。
“直接用代码编译的，又是同一个工程下，函数前后可以断在代码处，所以排除了静态库的影响。”老Y分析道，“难道？。。。”老Y此时心里冒出了一个大胆的想法，于是他和老J说，“VNC地址发我下，我VNC过去看看”。随后老Y连上了老J的电脑，打开了命令行，在工程目录中敲了一个命令，开始对所有的静态库查找断点函数的符号。当命令运行结束时，大家看到结果后心里似乎明白了老Y这么做的原因。原来，这个函数在另外一个静态库F中也存在一份。听到这个消息后，写下这个函数的另外一名同学老C想到了什么，突然说，“这个函数是是我从一个静态库中拷贝过来的，并且更新了代码。”
这时，老Y与老J都明白了问题所在，他们讨论道：“静态库X与F中有两个同样的符号，但是似乎真正链接到二进制中只保留了一个”，老J补充道，“是的，所以业务在运行时，本应该执行静态库X的代码，实际上却执行了静态库F，后者没有对数组指针赋值，便导致了闪退的出现”。
“我们要快速解决这个问题，PM还等着提交App Store呢”，老J说，“把函数名都改一下吧。”
“可是相似的代码还有挺多，一个个去修改风险比较高，直接加上namespace作隔离吧。”老Y提议，于是他们快速给相似的符号加上了新的namespace，再次本地打包验证，问题解决，此时时间刚过午夜1点。
本地验证通过之后，他们立刻在服务端打包，发给测试及业务同学验证。从问题出现到解决只花了一个多小时，如果不是因为debug无法进入断点，根本不可能这么快。在等待测试同学反馈给果时，老J问老Y，“怎么会想到去运行那个命令去查找所有静态库中的符号？”“其实也是比较偶然，已经是同一份代码进行编译，符号一定是同时被加载的，一些函数可以进入断点，另外一些无法进入，这有点说不通。我在前一家公司遇到过类似的问题”，老Y回忆起了往事，“但那时是动态库，两个库中也有相同的符号，当时现象并不是必现的闪退，而是概率性的出现。后来分析了很久才找到原因，结果是一个叫做 Global Symbol Interpose的问题，最终也是通过不同的namespace才解决了问题。”
老Y说：全局符号介入(Global Symbol Interpose)是在动态链接加载的过程中出现的，Linux采用广度优先搜索的方式来加载每个库中的符号，它会将每个符号都放到一个全局的符号表中，如果表中已经有了这个符号，那么它会忽略后面需要加载的符号
“但是为什么测试验证时，debug包不会出现闪退呢，按理说这是必现的问题”，老J问，“我推测是debug与release在链接两个库时的顺序不一致导致的，debug与release分别链接了不同的符号，导致debug是期望的符号，release是另外一个静态库的符号。但为什么这样我也还不清楚，现在也只是猜测”，老Y解释道。
正当他们讨论之际，测试同学反馈新包问题已解决。此时已经是夜里2点，PM还在等待着他们的结论，看到老Y他们在群里的结论之后，PM给老Y打了电话，老Y说明了结论和问题之后，PM问道，“为什么这个时候才发现？现在阻塞了提审，今晚肯定无法提交了，明天再提交吧。这个问题需要做一个复盘。”老Y想解释，想说这一定不是我们的问题，但无奈现在也只是推测，而且确实阻塞了提审，也没有作更多的辩解。挂了电话之后，老Y有些气愤，虽然他理解PM面临的压力，可是还没搞清楚状况就劈头盖脸一顿责问，这让老Y有些难以接受。/p p“我们先申请模块集成吧，为什么debug包无法出现闪退的问题明天继续分析”，集成申请之后，他们便合上了电脑，兴奋中夹杂着疲惫，沉沉的睡去。/p p老J和老Y快速解决了阻塞提审的问题，但似乎这个问题本身并不是很严重，更加严重的是为什么一个本该必现的问题这么晚才验证出来。老Y隐隐感到这里面有一个巨坑，也因为PM的一通电话，他下定决心要查明该问题，还团队一个清白。但没想到的是，这一查就是足足六天，接下来的六天时间里，老Y一步步找出了问题，原来那是一个隐藏了多年的bug。/p h2 id=第1天-嫌疑第1天 嫌疑/h2 p第二天老Y早早醒来，虽然前一天折腾到很晚才睡，但精神还不错。在去公司的路上，他就向负责构建的同学L描述了这个问题。L是打包这块的专家，他对打包过程极其了解。/p p互联网公司的上班时间相比传统公司较晚，9点公司楼下人依然很少。老Y在公司吃完早餐后，泡了一杯龙井茶振作精神，到了这个年纪，大家的标配似乎已经是枸杞菊花保温杯，但老Y还是喜欢喝点茶。一口热茶暖到胃里，老Y心想，“开始吧”。于是他打开了电脑，准备投入工作。/p p电脑是一台几年前的Macbook Pro，已经服役三年，很快就要退休。近段时间电脑越来越无法跟上老Y的使用强度，当然，也可能是跟不上软件的更新速度，隔三叉五的就会罢工一次。/p p对于前一天的问题，老Y已经有一个初步的推断，“debug与release包链接了不同的符号”，但为什么会这样，还需要等待构建专家L的分析。L收到了早上的消息后，与老Y通了电话，对问题进行了详细的询问，了解到问题之后，L心里也犯起了嘀咕，“这个问题还是得详细的查下，万一是打包平台的锅，影响可就大了。”于是他们先兵分两路，老Y准备下午的复盘文档，测试同学定了下午2点的复盘会议。而L去分析打包的问题。/p p老Y这么多年一直有个工作习惯，在遇到复杂问题时，会创建一个笔记，用于记录对问题的分析及进展。一方面有助于理清思路，防止被其它问题中断后无法迅速找到之前的状态。另一方面通过详细的记录，又可以后续对问题进行总结，遇到相似问题时能够通过这些记录找到当时详细的分析过程。于是他新建了一个笔记，取名：“XXX阻审问题分析”，笔记创建完成后，他首先记录了当前的问题与进展，接着开始准备复盘的文档，很快就将问题、解决方案、后续如何避免等写完，但其中有一个点还没有结论，也就是为什么提审前才发现问题，这个点老Y觉得可能问题没那么简单。/p p果然，在复盘文档刚刚写完时，L来了消息，印证了老Y的担忧。L发现不管是debug包还是release包，都是一样的符号，符号来自静态库F而不是静态库X。“如此说来，前面的推断都错了，并不是链接了不同的符号导致现象不同”，老Y说，然后接着问，“两个包在链接静态库的时候，依赖的顺序是一样的对吗？”L回答，“是的，顺序是固定的，和debug、release无关。”/p p“明白了，这样就不存在一个静态库的链接顺序导致不同符号被链接的问题”，老Y分析说，“但这样解释不通，如果是同样的符号，应该debug包也有同样的问题，而不仅是release包才出现闪退。”/p p“debug和release包除了宏及优化level不同以外，还有其它的区别吗？”老Y问L。/p p“有的，debug包里面多了一些测试模块，一会我做一些实验验证下是否是这些测试模块的问题”，L回答。接下来他便与测试同学一起验证有关测试模块的猜想。/p p老Y在等待L分析具体依赖差别的时候，又想了想，“昨天业务测试的反馈信息有些多，需要重新梳理一遍，究竟什么样的包出现，什么样的包不出现，先整理一个详细的列表出来。然后看看问题可能出现在哪个包中”，于是他将昨天修复问题前后各个场景都打了一个安装包并测试，结果发现只有在release包中才会闪退，其它所有安装包都正常。/p p“空指针访问时闪退是必然的，这样就可以集中精力定位为什么debug包不闪退，现在关键的问题在于找出空指针访问后，本该闪退的线程现在在做什么。先在本地尝试保持与debug包一样的版本依赖，看本地是否可以复现该问题。”于是老Y找到对应debug包依赖的各模块版本，然后搭建本地环境，开始调试。但让他没想到的是，本地不管是debug还是release，都是必现的闪退，程序停留在空指针访问的那一行，code class=language-plaintext highlighter-rougeEXC_BAD_ACCESS/code异常。/p p“奇怪，本地打包与后台打包怎么会表现不一样，难道后台还有很多其它的设置？”老Y很困惑。“既然本地无法复现这个问题，那只有增加一些日志，查看这个线程在空指针访问的前后在做什么”，老Y便在前前后后增加了大量的日志，期望这些日志可以告诉他发生了什么事。由于本地无法复现，所以他只好将代码提交，并依赖后台打出来的包才能够获得日志。提交代码之后，便安心等待后台的安装包构建。因为安装包依赖了数百个模块，所以每次的等待都需要接近十分钟的时间。在这期间，老Y又问了L那边的进展，L发现debug与release总共有6个测试模块不同，而去除了这些测试模块的debug包让测试同学去验证时，如期望的那样闪退了。“也就是说。。。”老Y激动的说，“没错，也就是这六个测试模块导致了本该出现的闪退被吞掉”，L回答，但L有一点忘了说，有一次测试时发现没有测试模块的debug包也未出现闪退。/p p“帮忙把这6个模块的名字发出来，我打算找出它们的负责人，然后拉个群问问看它们有没有在这些测试模块中catch住这个闪退。”老Y激动的说，L便去查找每个模块的负责人。正当此时，老Y增加日志的安装包已经构建完成，他下载并安装了这个包，然后熟练的在业务环境去验证。果然，这个包依然没有闪退。接着他获取了程序运行的日志并开始分析。/p p现象很奇怪，日志中有刚刚老Y增加的部分，在野指针访问之前，一切都正常，并且也证实了他们之前的猜想，代码走到了另外一个静态库F中，而这个旧的代码并没有初始化新增加的成员变量，这也是导致野指针的原因。可是，时间在这个线程仿佛停止了，野指针访问之后的日志都没有出现。同时，接下来的所有日志中再也没有出现该线程的其它任何活动。“奇怪，看起来像是这个线程在访问了野指针之后被干掉了一样，会发生这种事情吗？”，老Y疑惑的想，“难道是那几个测试模块把闪退捕获了，但没有处理好？”/p p这时，L拿到了这6个模块的名称，并找到了对应负责的同学。老Y将他们拉到一个新建的群中，然后描述了所遇到的问题：“各位测试模块的owner们，我们这边遇到一个棘手的问题，一个C++的必现闪退在debug包中不会出现，但在release包中会出现，对比发现debug包里面多了各位的测试模块。在必现闪退的地方，打了日志发现在闪退前的位置有日志，闪退后的位置没有日志，且整个线程也看起来被干掉了，所以想问下各位，有没有哪位的模块把C++的野指针访问异常catch住了。”在漫长的等待之后，有几个模块的负责人表示其负责的模块中并没有捕获闪退的代码。/p p老Y也继续尝试增加日志，发现不管是空指针，还是野指针，都一样不会闪退。刚开始他还怀疑是野指针是不是有可能访问到一个有效的地址而没有闪退，空指针才会闪退，但打印出来的日志粉碎了他这一猜想。时间就在他们不停的尝试与分析当中迅速流逝，夜幕很快就降临，在与团队同学一起吃饭时，他描述了问题以及当前的进展，大家也都表示这个问题很诡异，没有遇到过类似的问题。/p p当天是周五，看这天的进度，问题原因恐怕很难被快速定位出来，所以复盘也从2点推迟到4点，虽然最终阻塞提审的问题早就解决了，但是背后影响更大的问题还没有思路，如果这个问题不分析出来，复盘意义不大。所以老Y与测试同学讨论将复盘改在下周进行。/p p老Y所在的公司地理位置较好，楼下有个海边公园，每次吃完晚饭，大家便不约而同的绕着海边散步，缓解一天的疲劳。但今天老Y却没有和大家一起去，他打算尽量在周末之前搞定，这样便不用在周末还挂念此事，于是吃完晚饭之后，老Y立刻回到了办公位，他还是想着在本地复现这个问题，定位出具体哪个测试模块是罪魁祸首。他又对比本地与后台安装包的模块与版本是否完全一致，以防止出现遗漏。经过仔细对比，发现确实有几个模块在本地没有，于是他又尝试去后台下载了这几个缺少的模块，手动链接这些库，但还是和之前一样，本地必现的闪退，code class=language-plaintext highlighter-rougeEXC_BAD_ACCESS/code，无法在本地验证。/p p不知不觉折腾到11点多，老Y周末之前搞定的计划落空。很无奈，本地无法复现，只能依赖服务端。他找到L，“我们目前的结论是6个测试模块捕获了闪退异常，有没有办法能够在服务端尝试加载不同的测试模块，确定是哪个测试模块吞了这个闪退吗？”好在L也很重视这个问题，即便是周末，也答应了一定帮定位出是哪个模块，这让折腾一天疲惫的老Y心里感到一丝安慰。老Y查了一整天，但总有些力不从心的感觉，无法在本地复现问题，甚至打个日志验证都需要10分钟以上的时间，身心俱疲。老Y准备周末好好休息一下，调整好状态，周一接着查。/p h2 id=第2天-堆栈第2天 堆栈/h2 p深圳虽已是冬季，但仍和中部地区的初秋差不多，一件薄外套即可抵御寒冷。一年当中深圳从3月-11月都是夏季，只有此时的阳光显得温暖却不炎热，即便是正午，也可在户外活动。深圳遍布的公园草地上都铺满了大大小小的野餐垫，孩子们与爸爸妈妈享受这个快节奏城市里难得悠闲的时光，空中飘着各色各样的风筝，宛如秋游的景象，如果不看日历的话，绝难想到此时已是12月中旬。/p p老Y晚上睡得不好，好像做梦都在思考这个问题。早上起来之后，老Y回顾了昨天的分析过程，“这个线程后面没有了任何的日志，那么它到底在干什么？是线程被干掉了吗？还是说函数异常中止去做了其它的事情？”，“有什么办法能够获取到当前这个线程的状态？”，这几个问题一直萦绕在老Y的心里。整个上午老Y做什么事都一幅心不在焉的样子。午饭过后，突然间老Y有了灵感，“是否能用什么手段让整个应用崩掉，从而获取所有线程的堆栈？”/p p顺着这个思路，老Y想到一个办法。此刻也顾不得午睡，打开电脑便开始了尝试。他想在另外一个线程直接通过ObjC的方式来让程序崩掉，让一个程序崩掉的方法有很多，因为之前是C++的闪退无法处理，那么这里就通过ObjC的方式。很轻松的，老Y写了几行代码，直接创建一个ObjC对象，然后向它发送一个并不存在的方法。“这样便会出现对象无法响应方法的闪退了”，老Y自言自语道，“那么在什么时机来调用这个方法？先试试压后台吧。”老Y在一个类的code class=language-plaintext highlighter-rougeload/code方法中注册了应用压后台的通知，并在回调中调用了触发闪退的方法。/p div class=language-objc highlighter-rougediv class=highlightpre class=highlightcodespan class=k-/span span class=p(/spanspan class=ktvoid/spanspan class=p)/spanspan class=ntriggerCrash/span span class=p{/span span class=nXLog/spanspan class=p(/spanspan class=s@enter crash/spanspan class=p);/span span class=nUIView/span span class=o*/spanspan class=nview/span span class=o=/span span class=p[[/spanspan class=nUIView/span span class=nfalloc/spanspan class=p]/span span class=nfinitWithFrame/spanspan class=p:/spanspan class=nCGRectZero/spanspan class=p]];/span span class=p[/spanspan class=nview/span span class=nfperformSelector/spanspan class=p:/spanspan class=k@selector/spanspan class=p(/spanspan class=nhello/spanspan class=p)];/span span class=nXLog/spanspan class=p(/spanspan class=s@leave crash/spanspan class=p);/span span class=p}/span /code/pre/div/div p接着提交代码，等待漫长的打包结果。打包成功后，老Y立刻安装并进行了测试，首先是测试业务流程，空指针访问处没有闪退。接着程序压入后台，如他所料，闪退出现。老Y兴奋的赶紧去服务端捞取对应的闪退报告，可奇怪的是，服务端的最新报告日期竟然还是前一天，刚刚的尝试完全没有闪退报告。“难道是OOM了？只有这种情况下才没有报告”，老Y猜想。他又试了一次，更为奇怪的是，程序在还未进入后台时就崩了，服务端依然没有闪退报告。因为老Y的注意力都在没有查到闪退报告这件事上，所以他忽略了为什么程序还未进入后台时就崩溃这个细节。/p p这下老Y突然有些不知所措，怪事一件接一件的发生，但好在他已经做好了没那么顺利的心理准备，冷静下来之后想，“之前即使是发生了OOM，在Xcode中应该可以直接从手机上捞出来对应的报告，这是由系统生成的，可以试着捞一下”，老Y便连上手机，在Xcode中查看设备日志。/p blockquote p老Y说: 系统在应用闪退之后，会生成一份闪退报告，这里甚至会包含OOM类型的报告，可以通过Xcode的设备日志获取。/p /blockquote p在等待日志同步之后，老Y发现有两份闪退日志，但都不是OOM，而是普通的闪退。最新闪退是第二次的尝试，未压后台就崩掉，它与之前业务测试时发现的报告完全一致。挂在了空指针的访问处，闪退线程如下：/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcodespan class=nThread/span span class=mi54/span span class=nCrashed/spanspan class=o:/span span class=mi0/span span class=nXXX/span span class=mh0x0000000108ab01c0/span span class=nA/spanspan class=o::/spanspan class=nrun/spanspan class=p(/spanspan class=nImage/spanspan class=oamp;/spanspan class=p,/span span class=ktfloat/spanspan class=o*/spanspan class=p,/span span class=ktint/spanspan class=p,/span span class=ktbool/spanspan class=p)/span span class=o+/span span class=mi99549632/span span class=p(/spanspan class=nfile/spanspan class=p./spanspan class=ncpp/spanspan class=o:/spanspan class=mi259/spanspan class=p)/span span class=p.../span /code/pre/div/div p老Y又打开了另外一份报告，惊喜的发现这便是他这次实验想获取的那份。闪退的原因正如代码所写，在压后台时上面的code class=language-plaintext highlighter-rougetriggerCrash/code方法闪退，找不到对应的code class=language-plaintext highlighter-rougeselector/code。接着他向下查找其它线程。终于，在最后一个线程，那个本该闪退的地方出现了：/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcodespan class=nThread/span span class=mi54/span span class=nname/spanspan class=o:/span span class=nDispatch/span span class=nqueue/spanspan class=o:/span span class=ncom/spanspan class=p./spanspan class=nxxx/spanspan class=p./spanspan class=nxxx/span span class=nThread/span span class=mi54/spanspan class=o:/span span class=mi0/span span class=nXXX/span span class=mh0x00000001066d01c0/span span class=nA/spanspan class=o::/spanspan class=nrun/spanspan class=p(/spanspan class=nImage/spanspan class=oamp;/spanspan class=p,/span span class=ktfloat/spanspan class=o*/spanspan class=p,/span span class=ktint/spanspan class=p,/span span class=ktbool/spanspan class=p)/span span class=o+/span span class=mi99549632/span span class=p(/spanspan class=nfile/spanspan class=p./spanspan class=ncpp/spanspan class=o:/spanspan class=mi259/spanspan class=p)/span span class=mi1/span span class=nXXX/span span class=mh0x00000001066d01b4/span span class=nA/spanspan class=o::/spanspan class=nrun/spanspan class=p(/spanspan class=nImage/spanspan class=oamp;/spanspan class=p,/span span class=ktfloat/spanspan class=o*/spanspan class=p,/span span class=ktint/spanspan class=p,/span span class=ktbool/spanspan class=p)/span span class=o+/span span class=mi99549620/span span class=p(/spanspan class=nfile/spanspan class=p./spanspan class=ncpp/spanspan class=o:/spanspan class=mi259/spanspan class=p)/span span class=p.../span /code/pre/div/div p值得高兴的是，这个线程并没有被干掉，也没有从闪退的方法中退出，它就停在空指针访问的地方。但令人崩溃的是，堆栈中竟然有两个闪退的方法调用。“A::run的代码中并不存在嵌套调用，怎么可能堆栈中会出现两次？”，老Y再次感到不解。从两个frame的地址上看，两者相差12个字节，上面正常闪退的最后一个frame的地址与frame 0相同，都是995449632，那么下面的99549620是什么？“代码上来看，两者是同一行，那便只能从汇编上进行分析了。”/p p老Y打开了专业的汇编分析工具code class=language-plaintext highlighter-rougeHopper Disassembler/code，然后对着code class=language-plaintext highlighter-rougefile.cpp:259/code开始分析，259行代码是：/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcodespan class=mi257/span span class=kfor/span span class=p(/spanspan class=ktint/span span class=nj/span span class=o=/span span class=mi0/spanspan class=p;/span span class=nj/span span class=olt;/span span class=nsize/spanspan class=p;/span span class=nj/spanspan class=o++/spanspan class=p)/span span class=p{/span span class=mi258/span span class=nXLog/spanspan class=p(/spanspan class=err@/spanspan class=srun 5.2/spanspan class=p);/span span class=mi259/span span class=ktfloat/span span class=nx/span span class=o=/span span class=na/spanspan class=p[/spanspan class=mi0/spanspan class=p]/span span class=o*/span span class=nb/spanspan class=p./spanspan class=nc/spanspan class=p[/spanspan class=mi2/span span class=o*/span span class=nj/spanspan class=p]/span span class=o+/span span class=na/spanspan class=p[/spanspan class=mi1/spanspan class=p]/span span class=o*/span span class=nb/spanspan class=p./spanspan class=nc/spanspan class=p[/spanspan class=mi2/span span class=o*/span span class=nj/span span class=o+/span span class=mi1/spanspan class=p]/span span class=o+/span span class=na/spanspan class=p[/spanspan class=mi2/spanspan class=p];/span span class=mi260/span span class=nXLog/spanspan class=p(/spanspan class=err@/spanspan class=srun 5.3/spanspan class=p);/span span class=mi261/span span class=ktfloat/span span class=ny/span span class=o=/span span class=na/spanspan class=p[/spanspan class=mi3/spanspan class=p]/span span class=o*/span span class=nb/spanspan class=p./spanspan class=nc/spanspan class=p[/spanspan class=mi2/span span class=o*/span span class=nj/spanspan class=p]/span span class=o+/span span class=na/spanspan class=p[/spanspan class=mi4/spanspan class=p]/span span class=o*/span span class=nb/spanspan class=p./spanspan class=nc/spanspan class=p[/spanspan class=mi2/span span class=o*/span span class=nj/span span class=o+/span span class=mi1/spanspan class=p]/span span class=o+/span span class=na/spanspan class=p[/spanspan class=mi5/spanspan class=p];/span span class=mi262/span span class=nXLog/spanspan class=p(/spanspan class=err@/spanspan class=srun 5.4/spanspan class=p);/span span class=mi263/span span class=nd/spanspan class=p[/spanspan class=mi2/span span class=o*/span span class=nj/spanspan class=p]/span span class=o=/span span class=nx/span span class=o//span span class=nd/spanspan class=p;/span span class=mi264/span span class=nXLog/spanspan class=p(/spanspan class=err@/spanspan class=srun 5.5/spanspan class=p);/span span class=mi265/span span class=p}/span /code/pre/div/div p接着老Y用工具加载闪退版本的code class=language-plaintext highlighter-rouge.ipa/code包，再从闪退报告中找到偏移地址：code class=language-plaintext highlighter-rouge99549632/code，在工具中跳转到该偏移地址处，得到汇编：/p pimg src=/img/posts/6days-assembly.jpg alt=汇编 //p p凭借增加的日志，老Y很方便便找到了C++代码与汇编之间的对应关系。可是，即使从汇编中也无法找到栈的调用关系，理解不了为何出现两个code class=language-plaintext highlighter-rougerun/code。老Y接着在技术群里面询问了该汇编代码及闪退报告的奇怪之处，暂时也没有人从这段代码中找出来问题。/p p此时，L那边也来了消息，他做了很多实验，最后发现即使没有任何测试模块，debug安装包也不会闪退，也就是说闪退根本不是被测试模块吞掉了，而是另有其它原因。连续的两个暂时性的结论让老Y的分析走进了死胡同，不知不觉他已经坐在电脑前接近10个小时。唯一令老Y感到高兴的是，他知道这个线程还活着，并且停留在本该闪退的位置，同时也排除了测试模块的影响。这下他的分析可以聚焦在本该闪退的线程处。/p p暂时也没有其它的思路，老Y在“阻审问题分析”的笔记中记录了分析的过程及当前的进展，然后决定周日休息一天，放空大脑，周一再继续。/p h2 id=第3天-信号第3天 信号/h2 p经过周日充分的休息，老Y周一上班时感觉头脑很清醒，因为之前在笔记中做了详细的记录，他快速的回到了工作的状态，像是程序在函数调用时将调用前的状态压入堆栈，等函数调用完毕后又从堆栈中弹出一般。“突破口应该还是在这段堆栈之中，也许与闪退报告打过无数交道的框架同学可以给些建议”，于是老Y找到框架的同学老Q，描述了这个问题及现在的进展，老Q向老Y要了异常与正常闪退的报告。果然，老Y这一步走的非常正确，老Q很快便看出来了这份报告的异常之处。“这两份报告都是系统生成的，在生成的过程中可能会受到程序运行状态的影响，其寄存器等状态都不对，无法准确反应出闪退时刻的状态”，老Q继续补充道：“你需要找到应用自己生成的闪退报告。”/p p老Y听到这里很兴奋，终于他不用再纠着这段汇编不放，于是说：“我试过了让程序访问无效方法去获取堆栈，虽然应用闪退了，但是并没有在服务端捞到报告，只找到了这两份系统生成的报告。现在我并不需要程序真的崩掉，我只是想拿到程序当前的运行状态，知道那个线程在做什么。”老Y没有停下，继续道，“有没有可以让应用获取当前所有线程堆栈的方法？”/p p果然找对了人，老Q提供了一个API，可以像闪退时程序获取闪退报告一样去获取当前所有线程的运行状态，老Y赶紧将这一API加在了测试代码中。将之前的code class=language-plaintext highlighter-rougetriggerCrash/code方法换成了这个API去获取报告，并将报告打印在日志中。10分钟后，老Y在打好的包中再次尝试，日志中的堆栈出现在老Y眼前的那一刻，他长舒一口气，果然之前的两个code class=language-plaintext highlighter-rougerun/code不正常，堆栈与release包闪退堆栈一致，只有一个code class=language-plaintext highlighter-rougerun/code，“这就可以解释为什么空指针访问之后的日志都没有打印出来，线程完全停在这一行，没能向下执行”，可是除了PC错误以外，老Y暂时想不出还有什么办法能让线程停下。/p p老Y又盯着报告看了很久，突然注意到报告的最上面，这种类型的异常都是段错误code class=language-plaintext highlighter-rougeSIGSEGV/code，非法地址访问。突然老Y想起之前怀疑测试模块时的情形，当时怀疑某个测试模块拦截了闪退，就像在程序遇到闪退时，有时间来生成闪退报告一样。/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcodespan class=nException/span span class=nType/spanspan class=o:/span span class=nSIGSEGV/span span class=nException/span span class=nCodes/spanspan class=o:/span span class=nSEGV_MAPERR/span span class=nat/span span class=mh0x0/span span class=nCrashed/span span class=nThread/spanspan class=o:/span span class=mi54/span /code/pre/div/div p“是否可能是哪个模块处理了code class=language-plaintext highlighter-rougeSIGSEGV/code，但是没有处理好导致的？”老Y猜想，“先在demo中试一下，如果这个信号被注册，但是不处理，是否会有一样的现象？”，于是老Y构建了一个这样的demo，给code class=language-plaintext highlighter-rougeSIGSEGV/code设置一个仅打印日志的空handler，观察会发生什么：/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcodespan class=c1// ViewController.m/span span class=kstatic/span span class=ktvoid/span span class=nfhandler/spanspan class=p(/spanspan class=ktint/span span class=nsig/spanspan class=p,/span span class=nsiginfo_t/span span class=o*/spanspan class=ndont_care/spanspan class=p,/span span class=ktvoid/span span class=o*/spanspan class=ndont_care_either/spanspan class=p)/span span class=p{/span span class=nNSLog/spanspan class=p(/spanspan class=err@/spanspan class=ssigsegv/spanspan class=p);/span span class=p}/span span class=c1// viewDidLoad/span span class=c1// .../span span class=kstruct/span span class=ncsigaction/span span class=nsa/spanspan class=p;/span span class=nmemset/spanspan class=p(/spanspan class=oamp;/spanspan class=nsa/spanspan class=p,/span span class=mi0/spanspan class=p,/span span class=ksizeof/spanspan class=p(/spanspan class=nsa/spanspan class=p));/span span class=nsigemptyset/spanspan class=p(/spanspan class=oamp;/spanspan class=nsa/spanspan class=p./spanspan class=nsa_mask/spanspan class=p);/span span class=nsa/spanspan class=p./spanspan class=nsa_flags/span span class=o=/span span class=nSA_NODEFER/spanspan class=p;/span span class=nsa/spanspan class=p./spanspan class=nsa_sigaction/span span class=o=/span span class=nhandler/spanspan class=p;/span span class=nsigaction/spanspan class=p(/spanspan class=nSIGSEGV/spanspan class=p,/span span class=oamp;/spanspan class=nsa/spanspan class=p,/span span class=nbNULL/spanspan class=p);/span span class=nNSLog/spanspan class=p(/spanspan class=err@/spanspan class=scurrent SIGSEGV handler address: %p/spanspan class=p,/span span class=nsa/spanspan class=p./spanspan class=nsa_sigaction/spanspan class=p);/span span class=kstruct/span span class=ncsigaction/span span class=noldact/spanspan class=p;/span span class=nsigaction/spanspan class=p(/spanspan class=nSIGSEGV/spanspan class=p,/span span class=nbNULL/spanspan class=p,/span span class=oamp;/spanspan class=noldact/spanspan class=p);/span span class=nNSLog/spanspan class=p(/spanspan class=err@/spanspan class=scurrent SIGSEGV handler address: %p/spanspan class=p,/span span class=noldact/spanspan class=p./spanspan class=nsa_sigaction/spanspan class=p);/span span class=nNSLog/spanspan class=p(/spanspan class=err@/spanspan class=sbefore sigsegv/spanspan class=p);/span span class=ktint/span span class=o*/spanspan class=na/span span class=o=/span span class=nbNULL/spanspan class=p;/span span class=o*/spanspan class=na/span span class=o=/span span class=mi0/spanspan class=p;/span span class=nNSLog/spanspan class=p(/spanspan class=err@/spanspan class=safter sigsegv/spanspan class=p);/span span class=c1// .../span /code/pre/div/div p但当程序运行起来的那一刻，老Y再次懵掉，Xcode直接停留在于了code class=language-plaintext highlighter-rouge*a = 0/code那里，code class=language-plaintext highlighter-rougeEXC_BAD_ACCESS/code错误，虽然日志上可以看出设置了handler，但并没有进入到handler的回调中。“奇怪，明明注册了signal，不可能不回调吧，难道是不能debug？”，老Y抱着试试的想法，直接点开了demo，奇迹发生了，程序竟然没闪退。这可能是分析这个问题几天时间以来，老Y最为震惊，也收获最大的一个意外。他赶紧打开了code class=language-plaintext highlighter-rouge控制台/code，去抓取当前demo的日志，发现不停的打印着code class=language-plaintext highlighter-rougesigsegv/code的日志，而且程序并未崩溃。/p p为了获取handler处理之前的日志，老Y杀了进程，又重新进入demo，闪退之前的日志出现在了code class=language-plaintext highlighter-rouge控制台/code中，随后不停的打印code class=language-plaintext highlighter-rougesigsegv/code，闪退之后的code class=language-plaintext highlighter-rougeafter sigsegv/code一直没有出现。老Y兴奋的想，“这不就和我们遇到的情况一样吗？这个线程显然没有向下执行，一直在打印handler的日志，但主程序还活着”。此时，老Y获取到了handler的地址，“能否通过这个地址找到对应的符号名？”老Y想，code class=language-plaintext highlighter-rougeHopper/code是可以通过地址获取到符号名，但当前的地址是程序加载后符号的地址，包含了二进制本身的偏移，比如任意一个闪退报告：/p div class=language-cpp highlighter-rougediv class=highlightpre class=highlightcode span class=nsymbol/span span class=naddress/span span class=nimage/span span class=naddress/span span class=noffset/span span class=o|/span span class=o|/span span class=o|/span span class=mi0/span span class=nlibsystem_kernel/spanspan class=p./spanspan class=ndylib/span span class=mh0x00000001b2c74dd0/span span class=mh0x1b2c71000/span span class=o+/span span class=mi15824/span /code/pre/div/div p堆栈中有三个地址，分别是：/p ul lisymbol address: 程序运行时符号的地址/li liimage address: 对应image加载的首地址/li lioffset: 符号相对于image的偏移地址/li /ul p而老Y在日志中获取到的是code class=language-plaintext highlighter-rougesymbol address/code，还需要拿到code class=language-plaintext highlighter-rougeimage address/code才能够分析出最终的符号。如何才能够获取到code class=language-plaintext highlighter-rougeimage address/code？老Y已经驾轻就熟，在demo中又构建了一个无响应方法闪退，通过Xcode拿到了设备的闪退日志，这其中就有code class=language-plaintext highlighter-rougeimage address/code，很容易就可以计算出code class=language-plaintext highlighter-rougeoffset/code的值，并在code class=language-plaintext highlighter-rougeHopper/code找到符号的名称就是code class=language-plaintext highlighter-rougehandler/code。但每次code class=language-plaintext highlighter-rougeHopper/code处理的速度太慢，老Y有点不耐烦，换了更快的命令：/p div class=language-sh highlighter-rougediv class=highlightpre class=highlightcodeatos span class=nt-arch/span arm64 span class=nt-o/span demo.app.dSYM/Contents/Resources/DWARF/demo span class=nt-l/span lt;image addressgt; lt;symbol addressgt; /code/pre/div/div p“通过同样的方法可以在App中获取闪退之前注册的所有信号的handler”，老Y似乎看到了希望，因为每实验一次的耗费的时间太长，所以他仔细的设计了这个实验的方案，确保可以一次尝试得到所需要的信息：/p ol li首先在程序启动之后打印一次，获取初始的handler/li li刚进入业务打印，获取当前handler，防止被某个业务修改/li li正常执行业务场景/li li执行完成后打印handler，确认handler是否改变/li /ol p因为是在压后台的时刻调用获取handler方法，所以共总会压后台三次。修改完demo，老Y提交了代码并开始打包，然后在心里记录好操作的步骤，分析是否还有遗漏之处。经过了焦急的等待，服务端终于构建好安装包，老Y赶紧下载并进行测试。他小心翼翼的按照上面设计好的步骤来操作，一切都如他所期望的那样，程序依然没有崩溃。在最后一次压完后之后，他将手机放在了一旁，打开code class=language-plaintext highlighter-rougeMacVim/code开始分析日志。/p p所有的信号都被打印了出来，但有三点出乎他的意料之外，首先每一次压后台的操作获取到的handler都完全一样，这说明在他选择的这几个时机，程序的handler都没有改变。/p p第二个奇怪之处是很多信号的handler地址是0x1。老Y仔细查看了文档，发现原来它是和后面的flags一起使用，代表code class=language-plaintext highlighter-rougeSIG_IGN/code，意味着忽略该信号，通过code class=language-plaintext highlighter-rougesignal(SIGHUP, SIG_IGN);/codeAPI设置。/p p第三个奇怪的地方是只有code class=language-plaintext highlighter-rougeSIGABRT/code注册了handler，code class=language-plaintext highlighter-rougeSIGSEGV/code并没有handler。老Y又查了文档，了解到code class=language-plaintext highlighter-rougeSIGABRT/code是在程序调用code class=language-plaintext highlighter-rougeabort/code时才会抛出的信号。但空指针的访问一定是code class=language-plaintext highlighter-rougeSIGSEGV/code，前面的堆栈报告中也证实了这一结论。“难道code class=language-plaintext highlighter-rougeSIGABRT/code也能够处理非法地址访问的信号吗？”老Y有点不敢相信。/p div class=language-plaintext highlighter-rougediv class=highlightpre class=highlightcodeSIGHUP handler address: 0x1, mask:0, flags:2 SIGINT handler address: 0x1, mask:0, flags:2 SIGQUIT handler address: 0x1, mask:0, flags:2 SIGILL handler address: 0x0, mask:0, flags:0 SIGTRAP handler address: 0x0, mask:0, flags:0 SIGABRT handler address: 0x1013597ac, mask:0, flags:65 SIGSEGV handler address: 0x0, mask:0, flags:0 ... /code/pre/div/div p“先看看code class=language-plaintext highlighter-rougeSIGABRT/code的handler是哪个模块注册的吧”，老Y想，于是他通过前面的code class=language-plaintext highlighter-rougeatos/code命令获得了这个handler的符号名：code class=language-plaintext highlighter-rougeplcrash_signal_handler/code，接着在所有库中查了一次，找到它属于code class=language-plaintext highlighter-rougePLCrashReporter/code模块，这是一个开源的闪退报告库。“这个handler做了些什么？难道它还能处理code class=language-plaintext highlighter-rougeSIGSEGV/code吗？”/p p时间已经是深夜十点半，老Y的眼睛感觉有些干涩，一整天的注意力高度集中让身体有些吃不消。现在他已经不太想看code class=language-plaintext highlighter-rougeplcrash_signal_handler/code的源码，当前的精神状态下完全看不进去，只是随便在Google上搜了这个方法，找到一篇code class=language-plaintext highlighter-rougePLCrashReporter/code的a href=http://www.zoomfeng.com/blog/plcrashreporter-1.html源码分析文章/a ，简单浏览了一遍，但文章太长，他先记了下来，打算明天再看。/p p“从日志来看，code class=language-plaintext highlighter-rougeSIGSEGV/code并没有注册handler，只有code class=language-plaintext highlighter-rougeSIGABRT/code有一个奇怪的handler，难道是就是它导致的闪退被吞掉？”老Y看了看时间，发觉已经很晚，便想先以最快速的方式验证自己的猜想，“先试试如果将这个handler设置成空，是否就一定能够必现闪退了”。他将code class=language-plaintext highlighter-rougesignal(SIGABRT, SIG_DFL)/code加在了进入业务之后，“这样就可以在执行业务的代码之前将handler设置为默认值，如果还是不闪退，则表明不handler的问题。但如果闪退了，则表示是这个handler的影响。”老Y对自己的推理感觉很满意，再次提交代码并进行打包，接着他摘了眼镜，闭上眼睛休息，想着实验的可能性。“已经被这个问题折腾了好几天，这下是不是可以找到突破口了？”，老Y满心期待。/p p十分钟过后，安装包构建完成的通知惊醒了老Y，短短的时间他竟然睡着了，他戴好眼镜，开始尝试这个安装包，果然如他所料，App崩溃了。“太好了，这便足以证明是code class=language-plaintext highlighter-rougeSIGABRT/code handler的问题，接下来就只需要顺着这个handler做了去分析便能够找到问题所在”，老Y很激动，他将这一进展记录在笔记中，准备合上电脑之后，他突然像想起了什么，又打开电脑，补充了一句：“但这里还有一个问题，code class=language-plaintext highlighter-rougeSIGABRT/code为什么还会处理code class=language-plaintext highlighter-rougeSIGSEGV/code的信号？明天继续分析”。/p p写完后，老Y带着电脑离开了公司，此时已经接近12点。老Y开着车行驶在滨海大道上，虽然觉得有些疲惫，但因为三天来的分析终于有了进展，所以内心显得有些兴奋。他不停的想象着明天可能会有什么新的发现，“估计明天就能解决了吧”，老Y想。路上的车依然很多，不停有看似滴滴快车的电动车迅速从旁边驶过，广播中响起FM 104.9的音乐，午夜的音乐广播有种特殊的魔力，像是周围一切都暗了下来，为的便是有人对着耳边低声吟唱一般。不消一会便到了，老Y打开门，一盏温暖的夜灯亮着。/p h2 id=第4天-提速第4天 提速/h2 p前一天的发现让老Y信心满满，一大早来到公司就开始了接下来的实验。“昨天已经确定了是code class=language-plaintext highlighter-rougeSIGABRT/code handler还原成默认值之后就正常，但为什么它会处理本该是code class=language-plaintext highlighter-rougeSIGSEGV/code的信号？”带着这个问题，老Y开始在demo中做起了实验，在前面的demo中不再注册code class=language-plaintext highlighter-rougeSIGSEGV/code，取而代之的是code class=language-plaintext highlighter-rougeSIGABRT/code，其它没有任何变化。“如果程序依然不闪退，则表示空指针访问是可以被code class=language-plaintext highlighter-rougeSIGABRT/code catch住”，虽然不太相信，但老Y期望是这样的结果。/p p可是等到程序运行时，结果却与他所想的完全不同，不管跑多少次都会发生空指针访问的闪退。又看了看前一天打印出的日志，“难道除了信号本身，还有另外一个参数flags是65有关？”，老Y不解的猜到，他又将flags设置成65。可依然得到的是同样的结果。这个结果让老Y喜忧参半，喜的是空指针访问就应该是code class=language-plaintext highlighter-rougeSIGSEGV/code来处理，而不是code class=language-plaintext highlighter-rougeSIGABRT/code。忧的是他还要继续寻找原因，“为什么还原了code class=language-plaintext highlighter-rougeSIGABRT/code就会正常？”/p p老Y还得继续尝试分析原因，然后谨慎的在App中做实验，因为每次尝试都需要十分钟以上的时间，这让老Y感到效率太低，也是过去几天影响分析速度的一个很重要的原因。在刚刚的demo实验失败之后，他突然有了一个想法，足以大大加速这之后的分析过程。/p p因为在demo中测试信号时，他发现只有直接运行时，handler才会被处理，一旦连接Xcode联调，程序会直接挂在空指针的访问处，handler也无法被调用，老Y突然醒悟到：“之前本地调试时一直必现闪退，所以才在服务端打包。但会不会并不是本地与服务端打包的差别导致问题只在服务端的包中出现，而是由于使用Xcode联调？如果用本地打包，不联调，直接运行，会不会也能够重现出问题？”想到这点，老Y立马开始了尝试，首先它直接用Xcode调试，果然，程序挂在了空指针访问处。接着他停止了联调，直接打开程序，进入业务的页面。“会不会不闪退？”老Y竟然有些紧张，拿着手机的掌心微微出了些汗。/p p他尝试了一遍，奇迹般的，闪退并未出现。为以防是程序意外没有走到空指针的访问处，他又一次进行了尝试，依然没有闪退。随后老Y又去分析了一遍日志，确认了空指针访问处的代码的确被执行了，也通过压后台，得到了当时的堆栈，线程停留在空指针的那一行。“这样便确定了即使在本地也可以复现出问题，与服务端打包无关”，老Y为这次意外尝试得出的结论显得极其兴奋，因为所有的猜想与尝试都可以快速得到验证，而不需要经过服务端打包漫长的流程。/p p“从demo中看，只要是空指针访问都会产生code class=language-plaintext highlighter-rougeSIGSEGV/code信号，那是否同样可以直接构建这一闪退，而无需通过业务的复杂入口？”，为了进一步简化复现流程，老Y打算构建新的场景。在应用启动之后，他打算根据固定的事件来触发不同的操作，目前需要的操作包含三个：/p ul li触发空指针访问/li li打印堆栈/li li恢复code class=language-plaintext highlighter-rougeSIGABRT/code信号/li /ul p他同时重写了应用的首页，添加三个按钮分别触发这三个操作，如此一来整体测试的流程大大简化，验证一个猜想也可以控制在一分钟以内。在构建了这样一个简化版的操作之后，老Y在笔记中写下了他的三个验证用例：/p ol li程序启动后，先触发空指针访问，此时应该不会闪退；接着打印堆栈，可以确定线程卡在空指针访问处；/li li从日志中找到code class=language-plaintext highlighter-rougeSIGABRT/code信号的handler，分析是否依然是code class=language-plaintext highlighter-rougeplcrash_reporter_handler/code/li li重启一次应用，先恢复code class=language-plaintext highlighter-rougeSIGABRT/code信号，再次触发空指针操作，此时应该闪退/li /ol pXcode刷完应用后，老Y便开始了测试，用例1和3都如他所料，但第2个用例无法验证，因为code class=language-plaintext highlighter-rougeatos/code的命令需要dsym文件，但刚刚编译时dsym的配置未打开。老Y重新设置好编译选项后，再次安装好应用，继续上面的用例，正当老Y满怀期望之时，意外发生了。第一个用例失败，空指针访问竟然立刻发生了闪退，他有些不敢相信，再次打开应用执行了一遍，依然闪退，而且堆栈也指向空指针的访问处。“为什么会这样？dsym应该不会影响结果，难道是覆盖安装影响？”，老Y将信将疑，删除了旧包，重新进行安装、测试，没想到三个用例成功的通过了。/p p“如果猜想是正确的话，修改代码，再次覆盖安装，用例1应该会失败”，老Y为了证明这个猜想，增加了一行日志，覆盖安装进行了验证，结果如他所料，覆盖安装后会导致闪退行为正常，handler并不会捕获闪退。/p p这个意外的发现让情况似乎又变的更加复杂了些，老Y停下来整理了目前得到的信息，“现象是release包空指针访问闪退，但debug包空指针访问不闪退，可以确定的是code class=language-plaintext highlighter-rougeSIGABRT/code信号被注册，它捕获了本应是code class=language-plaintext highlighter-rougeSIGSEGV/code处理的空指针访问，这里还有些奇怪，刚刚在demo中也验证了code class=language-plaintext highlighter-rougeSIGABRT/code无法捕捉空指针访问，为什么App中就可以？如果将code class=language-plaintext highlighter-rougeSIGABRT/code的handler还原成默认，则闪退立刻会出现。信号的handler是code class=language-plaintext highlighter-rougeplcrash_reporter_handler/code，是由一个闪退报告的第三方开源库注册。另外一个意外获取的信息是首次安装运行时闪退才不会出现，但覆盖安装时会正常闪退。”/p p待老Y整理完所有的信息之后，他微微感到有些头痛，不停出现的奇怪现象让问题看起来越变越复杂，一个意外的出现可能随时就会推翻他之前得到的结论，但好在一个意外的发现也让得以本地验证，从而加速了问题分析的进程。这一天其它方面的事情也不断找上来，老Y不停的被打断，让他无法全身心的分析问题，来回之间的状态切换就像程序有资源消耗一样，也消耗着老Y的精力，在疲惫中老Y结束了一天的工作。/p h2 id=第5天-浮现第5天 浮现/h2 p老Y本想花时间去仔细分析code class=language-plaintext highlighter-rougeplcrash_reporter_handler/code的逻辑，可其源码的逻辑看似很复杂，于是他想先以更快的方式定位到原因。“既然是这个handler的影响，那么先看看这个handler具体是谁在什么时间注册的，如果关掉它是不是闪退就一定会出现？”基于这个想法，老Y先分析了App中code class=language-plaintext highlighter-rougemain/code方法所在的Portal模块，终于在一个code class=language-plaintext highlighter-rougeload/code方法中，找到了名为code class=language-plaintext highlighter-rougeenable_crash_reporter_service/code的方法，看起来它便是启动整个闪退报告服务的地方。/p p老Y尝试将这个方法注释掉，看是否闪退还会被捕获。如他所料，当闪退报告服务关闭之后，空指针立刻触发闪退。为以防万一，他再次取消该注释，重新运行，闪退没有发生，证明该方法调用确实是引起问题的原因。在验证了debug环境之后，老Y又切到release，不管闪退报告服务是否打开，空指针一定会造成闪退。“由以上实验可以得出结论”，老Y在笔记中记录到，“debug环境下的闪退服务导致了空指针访问闪退被吞掉，但release不受影响”。“debug与release有什么区别，即使是debug包，Portal所依赖的所有模块已经是release版本，只有Portal本身不同，同时还有link的参数有区别”，老Y又开始了他的分析。/p p在老Y尝试打开闪退报告服务时，他意外的发现了另一个现象，如果是debug包首次安装，第一次运行时空指针访问时闪退不会出现，但是杀了进程第二次运行时，空指针访问竟然在接近10秒之后出现了闪退。这个意外的收获让老Y对之前的覆盖安装问题有了全新的解释，“难道这就解释了为什么覆盖安装时空指针访问会闪退的原因了？”，老Y接着推测，“其实并不是与覆盖安装有关，而是首次运行与非首次运行的缘故”，“一定是应用在首次运行时写入了某个配置，第二次运行可以读到该配置所以没有走异常的逻辑，导致现象不同。之前认为debug包下闪退会被吞掉其实还有一个限制条件，即首次安装运行时才会发生”，老Y为了验证这一推论，他又找了测试同学帮忙尝试线上业务是否也是同样的现象，即第一次不会闪退，但杀进程后再次运行会正常闪退。不一会，测试的结论也同步了过来，果然如老Y所料，debug包不会吞掉所有的闪退，仅仅是首次运行应用时才会发生。于是老Y顺着这个思路，结合前面得到的debug与release的差别，开始分析Portal的代码。/p p因为Portal的代码并不多，很快老Y便发现了一个可疑之处，有一段被code class=language-plaintext highlighter-rougeDEBUG/code宏所包围的代码逻辑，用于清理缓存目录。本着快速排查问题的原则，老Y并不急于去分析这段代码，而是直接注释掉然后运行。奇迹发生了，debug包不再吞掉空指针的访问闪退。老Y感到十分兴奋，这下已经可以确定是由于闪退报告服务与缓存清理逻辑之间存在问题，可能是清理缓存导致了闪退报告服务的异常。/p p确定了清理缓存的逻辑存在问题之后，老Y开始仔细分析这段代码，想查出具体是哪个目录被清理掉导致的问题。经过几次试验，老Y定位到了code class=language-plaintext highlighter-rougeLibrary/Caches/code目录。他又对比了清理缓存前后目录中文件的具体差别，发现在清理之前有一个闪退报告的缓存目录。“这下可以确定问题所在，由于debug环境下闪退报告的缓存目录被清理，导致闪退报告服务出现问题，所以闪退被吞掉。但第二次运行时，由于code class=language-plaintext highlighter-rougeDEBUG/code宏之间的清理逻辑并不会被执行，因此后续的闪退并不会被吞掉。”/p p老Y接着分析，“闪退报告的目录应该是code class=language-plaintext highlighter-rougeload/code方法中被闪退报告服务所创建，它早于code class=language-plaintext highlighter-rougemain/code函数的执行，可在code class=language-plaintext highlighter-rougemain/code函数中缓存目录又意外被清理，如果将清理逻辑提前到闪退报告服务启动之前是不是就正常了？”，老Y进行了尝试，一切如他所料，这种情况下所有的闪退均能够正常出现。老Y还发现，除了首次安装以外，在切换线上与线下环境时，也会触发清理缓存的逻辑，如此一来，很有可能许多业务在回归验证时，会让本该出现的闪退被吞掉，将一些问题带到线上？认识到问题的严重性，他赶紧联系了Portal模块的负责同学，并告知现在分析出来的结论，由他接手剩余的工作。/p p至此，老Y已经定位到是由于闪退报告服务的缓存目录被清理导致了闪退被吞掉，看起来已经可以结出结论，但现在依然有两个问题没有得到合理的解释，这让老Y并不愿到此为止。/p ol li首先是code class=language-plaintext highlighter-rougeSIGABRT/code为什么会捕获空指针异常/li li为什么闪退报告的缓存目录被清理了之后闪退就会被吞掉？/li /ol p此时已经是深夜11点，老Y感到已经离“真相”不远，“估计明天这个问题就会解决了吧”，老Y在笔记上记录了当前的进展及第二天需要从哪里开始查起的思路，便合上电脑离开了公司。/p h2 id=第6天-真相第6天 真相/h2 p经过前面几天的分析，还剩下两个问题待解决，一是code class=language-plaintext highlighter-rougeSIGABRT/code为什么会捕获空指针访问异常。二是缓存目录被清理之后为什么会导致闪退报告服务异常并吞掉闪退。老Y一大早赶在其它同事过来之前就来到了公司，这样他就可以在正式工作开始之前快速解决剩余的问题，他已经花了太长的时间在这个问题上。/p p这两个问题都需要从code class=language-plaintext highlighter-rougePLCrashReporter/code的a href=https://github.com/microsoft/plcrashreporter/源码/a进行分析，现在该代码库由微软维护，但老Y没有立刻去分析源代码，而是从网上的文章入手，因为这能够帮助他以最快的速度找到切入点。这两篇文章详细的分析了code class=language-plaintext highlighter-rougePLCrashReporter/code的源码：a href=http://www.zoomfeng.com/blog/plcrashreporter-1.htmlPLCrashreporter源码分析其一/a及a href=http://www.zoomfeng.com/blog/plcrashreporter-2.htmlPLCrashreporter源码分析其二/a，它们很好的解释了code class=language-plaintext highlighter-rougeplcrash_signal_handler/code的工作原理，如此一来，前一天遗留的第一个问题得到了解决。/p p原来有两种类型的异常，平常在使用Xcode联调时遇到空指针访问会收到code class=language-plaintext highlighter-rougeEXC_BAD_ACCESS/code的错误，而这便是Mach层抛出的异常，这些异常会被host层转成对应的BSD信号，如空指针访问异常被转换成BSD标准的code class=language-plaintext highlighter-rougeSIGSEGV/code信号抛到出错的线程。前面所说的code class=language-plaintext highlighter-rougeSIGSEGV/code及code class=language-plaintext highlighter-rougeSIGABRT/code都是BSD类型的信号。而在code class=language-plaintext highlighter-rougePLCrashReporter/code中，处理的便是Mach类型的异常。但同时，它还注册了BSD的code class=language-plaintext highlighter-rougeSIGABRT/code信号，其handler为code class=language-plaintext highlighter-rougeplcrash_signal_handler/code，用于捕获最终的闪退异常，具体原因可以参考下面的源码注释：/p pimg src=/img/posts/6days-mach.png alt=SIGABRT //p p“如此一来，便可以解释为什么App没有注册code class=language-plaintext highlighter-rougeSIGSEGV/code却能够收到空指针访问类型的错误了，原来闪退报告模块已经从Mach层捕获了异常”，老Y喃喃道，“这个问题解决之后，接下来便只需分析为什么缓存目录被删除之后空指针访问异常被吞掉”。老Y直接clone了code class=language-plaintext highlighter-rougePLCrashReporter/code的源码，想看看最新的版本中这个问题是否已经处理。于是他模拟之前遇到的情况，在demo中启动闪退报告服务之后，立刻删除了缓存目录，运行起来之后果然空指针的访问无法引起闪退。“看起来这不是一个常见的case，否则这么久以来，怎么可能问题还没有修复”。/p p“因为是缓存目录被清理导致的问题，所以优先需要分析使用了该目录的代码”，老Y便开始搜索整个repo中使用该目录的代码，很快，他便找出一处a href=https://github.com/microsoft/plcrashreporter/blob/e9e257e65624cac025e6012315d2265ef2c8e1d6/Source/PLCrashReporter.m#L298可疑代码/a，如下图所示：/p pimg src=/img/posts/6days-bug.png alt=PLCrashReporter的bug //p p260行处的code class=language-plaintext highlighter-rougemach_exception_callback/code是PLCrashReporter处理Mach异常的回调函数，296行调用了一个函数code class=language-plaintext highlighter-rougemach_exception_callback_live_cb/code，这个函数会写闪退报告，如257行所示。但由于目标路径不存在，所以一定会写失败，从而296行的if条件命中，于是执行297与298处代码，问题就出了这里。/p p向上可以看到260行的返回值类型是code class=language-plaintext highlighter-rougekern_return_t/code，它是一个code class=language-plaintext highlighter-rougeint/code类型的code class=language-plaintext highlighter-rougetypedef/code，但是code class=language-plaintext highlighter-rougeKERN_SUCCESS/code与code class=language-plaintext highlighter-rougeKERN_FAILURE/code等定义如下：/p pimg src=/img/posts/6days-kern-success.jpg alt=KERN_SUCCESS //p pcode class=language-plaintext highlighter-rougeKERN_SUCCESS/code的值是0，而298处返回了code class=language-plaintext highlighter-rougefalse/code，它的值刚好是0，所以本应该是认为失败的场景，却因为返回false，而被当成了code class=language-plaintext highlighter-rougeKERN_SUCCESS/code，误认为是成功，程序逻辑出现异常，这应该是开发者笔误写错了返回值类型导致的问题。“为什么返回了错误的类型就会出现空指针访问被吞掉呢？”老Y继续刨根问底。他找到这个callback的声明处，发现注释中赫然写着：“如果返回了code class=language-plaintext highlighter-rougeKERN_SUCCESS/code，则线程会恢复执行”。/p pimg src=/img/posts/6days-plcrash.jpg alt=mach_exception_callback //p p“原来是这样，因为错误的返回值，导致了空指针的访问线程被恢复执行，立刻再次触发Mach异常，如此陷入了死循环”，老Y想，为了验证这一想法，他在298处增加了一段日志，运行之后如他所料，不断的在打印这处新增加的日志，由此也证明了他刚刚的猜想。/p p为了防止后续有人再遇到这个问题，老Y向code class=language-plaintext highlighter-rougePLCrashReporter/code的github仓库发起了一个a href=https://github.com/microsoft/plcrashreporter/pull/159MR/a。至此，由一个阻塞提审问题引发的耗时长达六天的问题追踪终于告一段落，老Y长长松了一口气，开如准备复盘文档，接下来估计还有一阵枪林弹雨。/p h2 id=后记后记/h2 p老Y与这个问题斗争六天的故事也至此告一段落，后续的复盘会议中依然发现还存在其它的问题，老Y又花了近一天的时间分析并找到解释，但这篇故事已经够长且显得啰嗦，后面的事情有机会再聊。/p p从最终的修复方案上来看，技术上的问题似乎非常简单：/p ol li首先是debug环境下清理缓存的逻辑需要优化，不能够在初始化闪退报告之后又清理其创建的缓存目录/li li然后是code class=language-plaintext highlighter-rougePLCrashReporter/code在写入闪退报告失败后的a href=https://github.com/microsoft/plcrashreporter/pull/159bug/a/li /ol p但就是这样一个简单的问题，为什么耗时如此之久才得出结论，导致复盘的时间一推再推，难点究竟在哪里，老Y在复盘时也进行了总结，主要包含以下几点：/p ul liApp复杂，依赖数百个模块，很难快速定位问题出自何处/li li开始几天只能在后台打包测试，Xcode无法调试，验证猜想的周期太长/li li后台debug包与release包相比依赖了一些测试模块，对推理过程造成干扰/li li测试过程中的出现一些奇怪现象：覆盖安装不出现、第一次不闪退第二次运行正常、不注册code class=language-plaintext highlighter-rougeSIGSEGV/code也异常等也给推理造成了困难/li li。。。/li /ul p正是由于以上一些因素组合起来，才导致了问题复杂度提升，让整个追查过程走了很多弯路。中间出现的异常现象在初次发现时，也曾被老Y当成是异常操作忽略过，并没有当成一回事，但最后发现所有测试中发现的所谓“奇怪”或偶然现象都不是偶然，而是某种条件下由bug引起的必然，都不应该被忽略，它们之中也许就藏着解决问题的关键性钥匙。在程序的世界里，任何问题只要能找出复现路径，问题就能得以复现。整个过程让老Y想起曾着迷过的侦探小说，解bug的过程就是破案的过程，任何蛛丝马迹都可能成为破案的关键。侦探根据获取的线索进行大胆猜想，并小心求证，一步步还原真相。/p p除了技术上的bug以外，该问题也同时暴露出沟通及开发流程中的一些问题，所以老Y也觉得在遇到这类问题时流程中有复盘这一环是个特别好的机制，开发、测试以不同的视角，对遇到的每个问题抛根问底，不会放过任何一个可疑的点，不存在无法解释的问题，任何问题都需要给出合理的解释，这样的复盘才不至于是为了流程而走个过场，才能保证如此大规模的App每次更新都维持最高的质量。出现问题并不可怕，可怕的是下次类似的问题一而再再而三的出现，这便是复盘的意义所在吧。/p p像这样的问题，作为一个程序员可能经常会遇到，尤其在如此大规模的系统中。程序员与bug缠斗的故事每天都在上演，而这六天，是老Y的故事。/p p(全文完)/p pfeihu/p p2021.01.07 于 Shenzhen/p
