种方案(Looper.loop和Choreographer.FrameCallback)可以判断是当前主线程是否发生了卡顿,进而在计算发现卡顿后的时刻dump下了主线程的堆栈信息。实际上,通过一个子线程,监控主线程的活动情况,计算发现超过阈值后dump下主线程的堆栈,那么生成的堆栈文件只是捕捉了一个时刻的现场快照。打个不太恰当的比方,相当于闭路电视监控只拍下了凶案发生后的惨状,而并没有录下这个案件发生的过程,那么作为警察的你只看到了结局,依然很难判断案情和凶手。在实际的运用中,我们也发现这种方式下获取到的堆栈情况,查看相关的代码和函数,经常已经不是发生卡顿的代码了。
如图所示,主线程在T1~T2时间段内发生卡顿,上述方案中获取卡顿堆栈的时机已经是T2时刻。实际卡顿可能是这段时间内某个函数的耗时过大导致卡顿,而不一定是T2时刻的问题,如此捕获的卡顿信息就无法如实反应卡顿的现场。
我们看看在这之前微信iOS主线程卡顿监控系统是如何实现的捕获堆栈。微信iOS的方案是起检测线程每1秒检查一次,如果检测到主线程卡顿,就将所有线程的函数调用堆栈dump到内存中。本质上,微信iOS方案的计时起点是固定的,检查次数也是固定的。如果任务1执行花费了较长的时间导致卡顿,但由于监控线程是隔1秒扫一次的,可能到了任务N才发现并dump下来堆栈,并不能抓到关键任务1的堆栈。这样的情况的确是存在的,只不过现上监控量大走人海战术,通过概率分布抓到卡顿点,但依然不是最佳的捕获方案。
因此,摆在我们面前的是如何更加精准地获取卡顿堆栈。为了卡顿堆栈的准确度,我们想要能获取一段时间内的堆栈,而不是一个点的堆栈,如下图:
我们采用高频采集的方案来获取一段卡顿时间内的多个堆栈,而不再是只有一个点的堆栈。这样的方案的优点是保证了监控的完备性,整个卡顿过程的堆栈都得以采样、收集和落地。
具体做法是在子线程监控的过程中,每一轮log输出或是每一帧开始启动monitor时,我们便已经开启了高频采样收集主线程堆栈的工作了。当下一轮log或者下一帧结束monitor时,我们判断是否发生卡顿(计算耗时是否超过阈值),来决定是否将内存中的这段堆栈集合落地到文件存储。也就是说,每一次卡顿的发生,我们记录了整个卡顿过程的多个高频采样堆栈。由此精确地记录下整个凶案发生的详细过程,供上报后分析处理(后文会阐述如何从一次卡顿中多个堆栈信息中提取出关键堆栈)。
采样频率与性能消耗
目前我们的策略是判断一个卡顿是否发生的耗时阈值是80ms(5*16.6ms),当一个卡顿达80ms的耗时,采集1~2个堆栈基本可以定位到耗时的堆栈。因此采样堆栈的频率我们设为52ms(经验值)。
当然,高频采集堆栈的方案,必然会导致app性能上带来的影响。为此,为了评估对App的性能影响,在上述默认设置的情况下,我们做一个简单的测试实验观察。实验方法:ViVoX9 上运行微信读书App,使用卡顿监控与高频采样,和不使用卡顿监控的情况下,保持两次的操作动作相同,分析性能差异,数据如下:
CPU |
1.07% |
1.15% |
0.08% |
|
Memory |
Native Heap |
38794 |
38894 |
100 kB |
Dalvik Heap |
25889 |
26984 |
1095 kB |
|
Dalvik Other |
2983 |
3099 |
116 kB |
|
.so mmap |
38644 |
38744 |
100 kB |
|
|
性能指标 |
2.4.5.368.91225 |
2.4.8.376.91678 |
上涨 |
CPU |
CPU |
63 |
64 |
0.97% |
流量KB |
Flow |
28624 |
28516 |
|
内存KB |
NativeHeap |
59438 |
60183 |
1.25% |
|
DalvikHeap |
7066 |
7109 |
0.61% |
|
DalvikOther |
6965 |
6992 |
0.40% |
|
Sommap |
22206 |
22164 |
|
日志大小KB |
file size |
294893 |
1561891 |
430% |
压缩包大小KB |
zip size |
15 |
46 |
206% |
从实验结果可知,高频采样对性能消耗很小,可以不影响用户体验。
监控使用Choreographer.FrameCallback, 采样频率设52ms),最终结果是性能消耗带来的影响很小,可忽略:
1)监控代码本身对主线程有一定的耗时,但影响很小,约0.1ms/S;
2)卡顿监控开启后,增加0.1%的CPU使用;
3)卡顿监控开启后,增加Davilk Heap内存约1MB;
4)对于流量,文件可按天写入,压缩文件最大约100KB,一天上传一次
痛点2:海量卡顿堆栈后该如何处理?
卡顿堆栈上报到平台后,需要对上报的文件进行分析,提取和聚类过程,最终展示到卡顿平台。前面我们提到,每一次卡顿发生时,会高频采样到多个堆栈信息描述着这一个卡顿。做个最小的估算,每天上报收集2000个用户卡顿文件,每个卡顿文件dump下了用户遇到的10个卡顿,每个卡顿高频收集到30个堆栈,这就已经产生20001030=60W个堆栈。按照这个量级发展,一个月可产生上千万的堆栈信息,每个堆栈还是几十行的函数调用关系。这么大量的信息对存储,分析,页面展示等均带来相当大的压力。很快就能撑爆存储层,平台无法展示这么大量的数据,开发更是没办法处理这些多的堆栈问题。因而,海量卡顿堆栈成为我们另外一个面对的难题。
在一个卡顿过程中,一般卡顿发生在某个函数的调用上,在这多个堆栈列表中,我们把每个堆栈都做一次hash处理后进行排重分析,有很大的几率会是dump到同一个堆栈hash,如下图:
我们对一个卡顿中多个堆栈进行统计,去重后找出最高重复次数的堆栈,发现堆栈C出现了3次,这次卡顿很有可能就是卡在堆栈3反映的函数调用上。由于采样频率不低,因此出现卡顿后一般都有不少的卡顿,如此可找出重复次数最高的堆栈,作为重点分析卡顿问题,从而进行修复。
举个实际上报数据例子,可以由下图看到,一个卡顿如序号3,在T1~T2时间段共收集到62个堆栈,我们发现大部分堆栈都是一样的,于是我们把堆栈hash后尝试去重,发现排重后只有2个堆栈,而其中某个堆栈重复了59次,我们可以重点关注和处理这个堆栈反映出的卡顿问题。
把一个卡顿抽离成一个关键的堆栈的思路,可以大大降低了数据量, 前面提及60W个堆栈就可以缩减为2W个堆栈(2000101=2W)。
按照这个方法,处理后的每个卡顿只剩下一个堆栈,进而每个卡顿都有唯一的标识(hash)。到此,我们还可以对卡顿进行聚类操作,进一步排重和缩小数据量。分类前对每个堆栈,根据业务的不同设置好过滤关键字,提取出感兴趣的代码行,去除其他冗余的系统函数后进行归类。目前主要有两种方式的分类:
1、按堆栈最外层分类,这种分类方法把同样入口的函数导致的卡顿收拢到一起,开发修复对应入口的函数来解决卡顿,然而这种方式有一定的风险,可能同样入口但最终调用不同的函数导致的卡顿则会被忽略;
2、按堆栈最内层分类,这种分类方法能收拢同样根源问题的卡顿,缺点就是可能忽略调用方可能有多个业务入口,会造成fix不