得物AppANR监控平台设计

见贤思齐

得物App ANR监控平台设计前言得物之前对于线上的ANR问题都是采用接入的Bugly平台进行问题收集和平台展示的，在体验中发现，无论是提供的信息对于解决问题的有效度、或者是对ANR日志聚合，都不太符合得物实际场景的需要。因此得物在参考业界各大厂商分享的ANR监控及治理方案后，我们开始着手建设自己内部的ANR监控平台，本文主要介绍ANR监控平台部分的实现，端上相关信息的采集实现不做阐述。ANR信息的处理在进行ANR日志的数据处理之前，首先整理下目前端上对于ANR问题上报的信息内容，主要包括以下几点信息：ProcessErrorStateInfotomstone信息主线程的堆栈采样信息主线程Looper Message历史调度的Message信息、当前处理的Message、未处理的Message队列App状态信息应用前后台状态应用运行时长...以下针对上述几个关键信息的处理，进行说明。ProcessErrorStateInfo解析ProcessErrorStateInfo是通过ActivityManager的getProcessesInErrorState()函数获取的，主要包含以下信息：processNamepiduid??tag (如果ANR发生在Activity、Service等系统组件上，则tag会被设置为对应的组件名）shortMsg（ANR信息的简短描述）longMsg（ANR的详细信息）这里主要关注的时longMsg的信息, 通过正则匹配的方式，从longMsg中可以解析出以下关键信息：ANR发生的组件ANR触发的原因tomstone信息解析关于Android tombstone文件包含的信息可以参考debuggerd中tombstone的相关代码 ，得物目前在线上采用的是iQiyi开源的xcrash进行ANR tomsbtone信息的采集。?采集的tombstone文件中主要包含以下信息Crash相关元信息Crash类型 (anr、java 、native)应用启动的时间Crash的时间应用版本号系统版本ABIpid、tid、Crash线程名虚拟机GC相关信息ANR时各线程的现场信息线程当前调用栈线程优先级prio线程状态持有、或者等待的锁信息线程nice值、utm、stm等信息logcat信息open filesmemory info....对xcrash的tombstone信息的解析，也直接采用的是xcrash中内置的代码实现。Looper Message回溯信息的解析在LooperMessage回溯是指对系统主线程Looper对消息记录的历史(也包括未处理的消息记录)，从Message的处理状态上分类，包含三类Message：已处理的Message当前正在处理的Message未处理的Message对于已处理的Message，采集了Message执行的耗时时间（Wall time），以及CPU分配执行的时间（CPU time），根据这两个时间的可以大致判断，主线程CPU的调度情况，如果两者之间的差值较大（CPU time只占Wall time的30%以下) ，考虑可能存在比较严重的线程调度抢占问题。对于未处理的Message，主要是可以用来观测当前Message的调度延迟情况、是否存在消息积压过多等case。堆栈采样信息(method trace)解析得物会在App运行时，每隔一定的时间间隔（50ms）采集主线程当前的执行堆栈，总计会保存10S~20S 的线程调用栈，当发生ANR时，采集的堆栈信息会随ANR信息一起上报。通过在后台对采集的堆栈进行处理，可以预先分析出其中较为耗时的函数，在这里简单描述下对函数采样数据的分析处理方式。首先将采集的堆栈遍历解析，并按照函数的调用关系转成NodeTree的形式，遍历过程中，记录每个函数的耗时。从根节点开始，层级遍历 MethodNodeTree，找出所有耗时大于一定阈值的函数。过滤掉一些白名单函数，比如 com.android.internal.os.ZygoteInit.main 、android.app.ActivityThread.main?部分代码public class MethodNode { ? private List children = new ArrayList(); ? ?//method cost time ? ?private int cost; ? ? ?private String fullMethodName; ? ?private JavaStackFrameSnapshot javaStackFrameSnapshot; ? ?}ANR日志的聚合在APM平台中，对于issue类型的事件，一个很重要的处理环节 就是对数据的聚合过程。对于端上上报的ANR日志同样也需要进行聚合处理，这样可以更好的对ANR问题进行分类，评估不同问题在线上发生ANR的严重程度，根据严重程度进行集中治理。聚合策略在生产环境中，设备发生ANR的原因多种多样，简单归类的话可以分为以下几种情况：主线程慢函数执行导致比如主线程执行繁重的代码，比如对大数据量的排序主线程上执行IO操作Looper消息调度异常锁等待、死锁系统负载较高、当前进程的CPU调度受到影响系统binder服务异常....其他异常情况针对可能因为慢函数导致的ANR问题，通过上节的 “堆栈信息解析”环节已经解析出所有耗时大于一定阈值的应用内函数，在符合一定条件的情况下（主线程CPU调度正常）可以按照耗时函数进行聚合。对于其他的case，我们先简单的按照发生ANR的组件+ANR触发的原因两个关键信息进行聚合，先按照这种比较粗的粒度进行聚合，再进行分析，如果发现一定的规律后，可以在平台支持一些 特定规则的自定义聚合能力进行数据聚合。平台体验这个章节分享的是，得物针对ANR问题在平台功能上的体验设计，重点主要是说明如何展现现有的这些数据信息，帮助开发者更好的发现及定位问题。对于每一个上报的ANR日志来说，除了一些通用的埋点信息外（如userId、sessionId、deviceOs等），重点是对于ANR该问题相关的上下文信息的展示。问题列表首先ANR日志在经过聚合流程后，被分成一个个ANR ISSUE，每个ISSUE都有单独的处理状态及趋势 ，以便进行问题治理及问题趋势的跟进。在应用整体上，也提供了相应维度的趋势图可以观测目前线上ANR的情况。问题详情在问题列表页，可以大概概念当前ANR有多少个问题，每个问题的趋势及处理状态，当点击每个问题时，会跳转到该“聚合问题”的详情页，在聚合算法实现较为完备的情况下（在实际场景中，以ANR目前原因的多样性，较难达到），每个问题详情都是一个特定原因导致的ANR、或者是发生在某一个特定的应用组件上的ANR。在问题详情页，同样可以展示该特定问题的发生趋势，以及对问题处理状态等，但更为重要的是这个问题，平台提供了哪些关键元素信息来帮助开发者定位ANR问题。日志详情在每个ANR ISSUE详情页中，每个ISSUE都是一堆ANR上报的日志集合，即ISSUE跟Log，是一个一对多的关系，在问题详情页，可以查看该问题下面上报的所有异常日志，点击每个异常日志时，可以查看该日志的详细信息。在日志详情部分，ANR平台将上个小节解析的所以信息，包括主线程Message回溯信息、method trace信息，各进程CPU使用率等，以更友好的可视化方式进行展示。ANR日志基础信息的展示ANR触发的组件ANR触发的原因ANR发生时的应用的前后台状态应用运行时长....ANR后一段时间各进程CPU的使用率信息这里主要是展示端上收集上来的各进程的CPU使用率信息，使用率上分为用户态和内核态。在这里主要查看两个方面的信息，当前进程的CPU使用率有无异常，以及在用户态和内核态的分布情况。另外一个方面是查看其它进程的CPU使用率，考虑是否可能出现由于其它进程CPU使用率过高，而影响当前进程的情况。ANR 时各线程现场信息展示线程现场信息，主要是查看主线程是否有可能发生死锁、以及其它线程的运行情况，是否有可能出现其它工作现场过多，导致当前线程调度受影响的情况等。Looper消息回溯信息的展示Looper消息的回溯是可以从主线程处理Message的视角看消息的分发、处理情况。ANR发生的原因除了耗时函数外，也可能是由于主线程CPU的调度受到了瓶颈、或者是向Looper发送了过多消息导致等诸多原因。logcat信息从logcat信息中，可以辅助验证、获取ANR发生前后的一些信息，有时候从logcat中的异常日志中也能定位出问题。函数执行火焰图（Flame Chart）的展示火焰图可以以全局的视角来看应用函数执行的情况，更直观的分析出可能导致出现ANR的函数。使用ANR监控平台排查问题的思路简单来说，通过现有的平台，可以从以下几个方面来分析ANR问题：从ANR的前后台状态、应用运行时长、进程CPU使用率、Message Trace中Message 的CPU time、Wall time的差值大概对当前应用的CPU调度能力有一个评估。从火焰图中分析是否有明显耗时的业务代码。从MessageTrace中看是否有明显异常的消息处理（单个消息处理过长、Message数过多 等情况）。从CPU使用率上。看应用进程user和kernel的使用占比有无异常，如果kernel使用较高，则分析是否发生了大量的系统调用, 如果user层的使用率较高，则说明在业务侧有较多繁重的任务执行。查看kswapd0 CPU使用率是否较高，如果CPU使用率比较高，则说明系统内存资源不足，此时系统正在进行频繁的内存交换 (内存空间和磁盘空间的交换)，占用系统的CPU及io资源,因此会影响整机性能。查看systemServer的CPU使用率,是否是由于系统服务的CPU使用率过高，导致当前进程无法分配到足够的时间片。从logcat排查问题。从logcat中观察gc相关的信息，是否有可能是由于内存严重不足，执行blocking gc导致的ANR，这里也可以结合线上的内存采集信息，将ANR发生前后的内存使用信息一同上报。查看kernerl相关的日志，是否有lomemorykiller iowait等系统相关资源不足的情况。部分问题治理分享本节是分享在ANR平台上线后，利用ANR平台定位到的一些ANR问题。调用Kotlin Function对象的toString函数调用导致ANR在排查ANR日志时，发现有多个ANR日志中，Kotlin的KfunctionImpl.toString都比较耗时，火焰图case如下：于是在线下对Kotlin的该函数进行了测试，在demo中参照火焰图中的业务代码进行了场景还原。结果发现，一个简单的toString调用，在demo中耗时达到了118ms。经过一系列的变量测试发现，在引入kotlin后，并且引入了kotlin-reflection库的情况下，调用Kotlin Function对象的toString函数时耗时非常严重。因此在业务代码中要注意，不要对kotlin的函数对象直接或者间接的触发toString操作。主线程执行View.getDrawingCache进行bitmap转换从队列中，发现大量的消息已被阻塞，并且在前序的Mesage处理记录中，发现有耗时900ms的消息处理。转到对应的method trace中发现，卡顿主要是由于在主线程对Webview获取drawingCache导致的。在线下进行测试时，可能在正常情况下该函数的耗时并没有这么耗时，因此暂不能确定该问题是如何引起的，但是从代码实现的角度，也不应该在主线程执行类似的耗时操作，因此可以将该操作移入异步线程执行。SP等待任务造成的ANR问题在ANR平台上线后，发现目前收集的用例中 有大量数据是由于 系 统组件在onPause、onStop等相关流程需要等待所有异步的SP写入操作完成造成的。得物目前的业务都已使用MMKV替换SP，主要使用SP的场景都是接入的一些三方SDK，而这些SDK一般不需要对这部分数据在组件跳转间 对“异步任务数据写入完成”的强保证，因此得物对这部分系统的机制进行了HOOK，在这部分HOOK功能上线后，ANR率有了明显下降。后续优化迭代方向从目前ANR平台上线后 问题的治理情况上来看，大部分容易解决的问题都是从火焰图上分析出明显耗时的业务代码从而解析的，在实际的线上场景中，目前还是发现有一些特定的case以现有上报的日志信息无法明确给出发生ANR的根本原因。后面会根据每种case，加强其他方面的监控能力，来协助定位问题。端侧其他上下文信息收集的增强比如在线上发现，某些ANR问题耗时函数卡在一个简单的File.exist函数调用上，针对此类问题，后续可能需要结合native层对file io操作的一些监控、hook来协助定位问题。端上Method Trace性能优化目前得物App在端上进行Method Trace的方案是 在子线程定时通过主线程的Thread对象 调用getStackTrace进行采集，虽然该函数的执行是在异步线程，但是在虚拟机底层在非当前线程获取某个线程的堆栈时，会先suspend对应的线程，获取完成后再resume。?因此如果对主线程抓起堆栈的频率较为频繁的话，势必会影响主线程正常函数的执行。我们的MethodTrace的要求是应该尽量保证其只产生极小的运行时开销，避免为了监控反而影响应用性能，虽然目前的这套采样方案，控制的最小采样间隔为50s，对性能影响不大。在Facebook的profilo开源库中有一套异步非阻塞获取线程堆栈的方案，不过其目前只开源了适配了 Android 9及以下的版本。字节跳动的西瓜视频分享了另外一种Java Method Trace，不过该方案最终也是需要suspend thread, 对性能也是有一定影响，不过在实现上也是一个可以参考的方向。平台测MessageTrace体验优化目前Looper Message Trace功能和Method Trace（函数执行火焰图）功能是两个比较独立的功能，当我们在Message Trace功能中发现某个消息比较耗时，正常情况下是希望能够直接看到该消息具体做了什么操作，因此在平台测可以做的一个优化是， 当点击Message时，根据这个Message的处理的开始结束时间，自动截取对应时间的函数堆栈片段，进行信息展示。ANR时间的区分端上收集上来的Message信息及函数采样信息，其实是包含了ANR之后的，因为从ANR触发到应用程序捕获再到收集信息 存在一定的时间差，因此从问题分析的角度上，这个时间点需要做一个明显的区分。参考资料https://www.ssw.uni-linz.ac.at/Teaching/PhDTheses/Hofer/PhD.pdfhttps://mp.weixin.qq.com/s?__biz=MzI1MzYzMjE0MQ==&mid=2247489902&idx=1&sn=bfdf9f48dc6dc973722b5dcab9cd5882&chksm=e9d0d28cdea75b9ad255eb5de227240d2e6f0e9d66e562d3f49cf69f8ed4127c9954ef21bb6d&scene=178&cur_album_id=1780091311874686979#rdhttps://mp.weixin.qq.com/s?__biz=MzI1MzYzMjE0MQ==&mid=2247489902&idx=1&sn=bfdf9f48dc6dc973722b5dcab9cd5882&chksm=e9d0d28cdea75b9ad255eb5de227240d2e6f0e9d66e562d3f49cf69f8ed4127c9954ef21bb6d&scene=178&cur_album_id=1780091311874686979#rdhttps://mp.weixin.qq.com/s?__biz=MzI1MzYzMjE0MQ==&mid=2247488116&idx=1&sn=fdf80fa52c57a3360ad1999da2a9656b&chksm=e9d0d996dea750807aadc62d7ed442948ad197607afb9409dd5a296b16fb3d5243f9224b5763&scene=178&cur_album_id=1780091311874686979#rdhttps://androidperformance.com/2019/09/18/Android-Jank-Due-To-Low-Memory/#%E6%95%B4%E6%9C%BA%E5%8D%A1%E9%A1%BF-amp-amp-%E5%93%8D%E5%BA%94%E6%85%A2关注得物技术，做最潮技术人！文｜Knight-ZXW