0%

一个 Crash 的排查历程

背景

原本风平浪静的一天,被几个用户反馈的问题打破了…

突然有几个用户来反馈,更新版本后,直播间里偶尔会卡住,无法做任何操作,并且最后闪退

排查过程

Crash 平台找崩溃信息,但是没有相关信息,捞日志,看用户操作路径,也没找到比较有价值的信息,比较诡异,但是用户确实闪退了,因此猜测这个 Crash 没有被工具捕获到,对于应用无法捕获 Crash,比较常见的有 SIGKILL 信号量,比如 exit(), kill() 等函数调用,iOS 系统杀进程引起,比如 WatchDog 杀进程、OOM 等,而且这些 Crash 信息在用户系统中会有保留,因此联系用户,引导他在 设置-隐私-分析与改进-分析数据 里找到以应用名开头的日志,然后分析日志

分析日志

关键信息如下:

Exception Type: Crash 类型,常见的类型以下这些,其中 UNIX 信号 和 Mach 异常是一一对应的:

Mach 异常 UNIX 信号 简介 案例
EXC_BAD_ACCESS SIGBUS 总线错误 1 内存地址对齐出错
2 试图执行没有执行权限的代码地址
EXC_BAD_INSTRUCTION SIGILL 非法指令,即机器码指令 不正确 1 iOS 上偶现的问题,遇到之后用户会连续闪退,直到应用二进制的缓存重新加载或重启手机。此问题挺影响体验,但是报给苹果不认,因为苹果那边没有收集到,目前没有太好办法。因为 iOS 应用内无法对一篇内存同时获取 w+x 权限的,因此应用无法造成此类问题,所以判断是苹果的问题。
EXC_ARITHMETIC SIGFPE 算 术 运 算 出 错,比如除 0 错误 算术运算出错,比如除 0 错误 iOS 默认是不启用的,所以我们一般不会遇到
EXC_SOFTWARE (我们在 Crash 日志中一般不会看到这个类型,苹果的日志里会是 EXC_CRASH SIGSYS 系统调用异常
SIGPIPE 管道破裂 1 Socket 通信是可能遇到,如读进程终止时,写进程继续写入数据。2 根据苹果的文档,我们可以忽略这个信号: 官方文档
SIGABRT abort() 发生的信号 典型的软件信号,通过 pthread_kill() 发送
SIGKILL 进程内无法拦截 1 exit(), kill(9) 等函数调用 2 iOS 系统杀进程用的, 比如 watchDog 杀进程

Exception Codes:和异常是有关的处理器指定信息,这些信息会被编码成一个或者多个64位二进制数字。一般来说,这个字段不应该存在,因为 Crash report 生成时会把 Exception code 转化成可读的信息并在其它字段进行体现

Exception Note:不特指某一种异常的额外信息。如果这个字段包含”SIMULATED”(不是Crash),则进程并没有发生 Crash,而是在系统层面被 Kill 掉了,比如看门狗机制

为了防止一个应用占用过多的系统资源,苹果工程师门设计了一个“看门狗”的机制。“看门狗”会监测应用的性能。如果超出了该场景所规定的运行时间,“看门狗”就会强制终结这个应用的进程。
开发者们在 Crashlog 里面,会看到诸如 0x8badf00d 这样的错误代码(看起来很像 bad food,看门狗吃到了坏的食物,不嗨森)
看门狗触发条件如下:

触发时机 看门狗出动的时间
启动 20秒
恢复运行 10秒
悬挂进程 10秒
退出应用 6秒
后台运行 10分钟

Termination Reason:当进程被终止时的原因及信息。关键的信息模块,不论是进程内还是进程外,当遇到一个致命错误(fatal error,例如 bad code signature,缺失依赖库,不恰当的访问私有敏感信息等)。MacOS Sierra,iOS 10, watch OS 3 和 tvOS 10 已经采用新的架构去记录这些错误信息,所以这些系统之下的 crash report 会在Termination Reason 这个字段里描述 error message 信息

Termination Description:进程被终止时的详细信息

Triggered by Thread:指出异常是在哪个线程发生的

用户日志 Crash type 为 EXC_CRASH,对应的信号为 SIGKILL,属于进程内无法拦截的 Crash,Exception Note 为 Namespace SPRINGBOARD, Code 0x8badf00d,正是被看门狗 kill 掉的,再结合 Termination Description 来看,exhausted real (wall clock) time allowance of 10.00 seconds,是由悬挂进程超过10秒触发的,Triggered by Thread 为 0,表示主进程,至此,结论出来了:由于主线程被阻塞超过10秒,进程被而被看门狗 kill 掉,原因找到,现在就看堆栈信息,找到主线程在哪里被阻塞的

符号化

主线程原始堆栈如下,需要进行符号化后才能看到具体调用,这里我选用 symbolicatecrash 进行手动符号化,symbolicatecrash 是 Xcode 自带的命令行工具, 在 /Applications/Xcode.app/Contents/SharedFrameworks/DVTFoundation.framework/Versions/A/Resources/symbolicatecrash, 这个工具可以帮助我们将整个 Crash 日志符号化:

  • 拷贝工具到自己的文件夹(比如 crash )
  • 进入 crash 文件夹,输入命令:
1
export DEVELOPER_DIR=/Applications/Xcode.app/Contents/Developer​
  • 把待符号化的日志和 dSYM (符号表) 放入 crash 文件夹,其中 dSYM 要与 crash 日志中的 UDID 保持一致,拿到的用户日志后缀是 ipa,需要改成 crash
  • 一切准备就绪后,在该文件夹内,在终端输入符号化命令:
1
./symbolicatecrash /Users/你的电脑用户名/Desktop/crash/xxxx.crash /Users/你电脑的用户名/Desktop/carsh/xxxx(dSYM文件名字).dSYM > xxxx.crash

输出结果:

有了明确的堆栈,问题就好解决了

看代码得知,主线程最终被阻塞在 reportPackageUseResult:errType:errMsg: 方法上,通过看方法的实现,整个方法调度过程都用 @synchronized 锁起来了,涉及到锁,就可能有死锁、等待锁的情况,该方法在子线程也会调用,并且在堆栈里也找到了子线程调用

很明显,子线程先调用 reportPackageLoadResult:url:otherParameterDict: 方法获取了锁,并且之后在调用 currentReachabilityString 方法在521行被阻塞,而后续主线程调用时,由于子线程获取了锁没有释放,主线程也就被阻塞,等待子线程释放锁,该方法的作用是获取当前网络类型,521行的代码如下:

1
CTTelephonyNetworkInfo *networkInfo = [[CTTelephonyNetworkInfo alloc] init]

仅仅是初始化一个 CTTelephonyNetworkInfo 对象,为何会造成阻塞?
答案未知,这块代码最近版本都没改动,而且此类问题是最近的版本才有反馈,所以怀疑苹果系统底层获取网络运营商之类的方法或机制有所改动,导致该方法在某些场景某些机器下造成阻塞,在网上搜索,发现也有人遇到过该问题 https://www.jianshu.com/p/c21dd12ccef6,可以把每次初始化改成应用内只初始化一次来解决

解决

  • 把锁的粒度改小
  • 把 CTTelephonyNetworkInfo 对象每次初始化改成应用内只初始化一次
  • 添加埋点监控,检测该对象初始化的耗时

上线后,用户反馈没问题了。

总结

  • 对于无法捕获的 Crash,需要用户提供 Crash 日志,并且了解日志中每个字段的含义及 Crash 的类型
  • 掌握符号化的工具及方法,symbolicatecrash
  • 在使用锁时要注意锁的粒度,不宜过大

参考