贝壳APPTopExperience系列Android方法耗时统计工具

想梦

贝壳APP Top Experience系列 | Android方法耗时统计工具 贝壳APP Top Experience系列 | Android方法耗时统计工具 贺宇成@贝壳找房 贝壳产品技术 贝壳产品技术 “贝壳产品技术公众号”作为贝壳官方产品技术号，致力打造贝壳产品、技术干货分享平台，面向互联网/O2O开发/产品从业者，每周推送优质产品技术文章、技术沙龙活动及招聘信息等。欢迎大家关注我们。 242篇内容 2020年11月27日 18:18 背景Part 1Top ExperienceAPP的性能、稳定性对于用户体验的重要性不言而喻，一个好的体验效果能正向推动业务的发展。为此我们建立了Top Experience项目，用来提升贝壳App的综合性能、打造行业顶级体验效果。Part 2贝壳冷启动优化对于用户体验而言，App的启动速度是用户第一印象，如果一个App的启动时间过长很可能会导致用户不悦从而打消进一步使用App的念头。为此App的启动优化是我们Top Experience项目的首要优化点。针对App的启动来说可以细化为三种类型的启动：冷启动、温启动、热启动。后面两项在系统的优化下已经足够完善和快速了，所以冷启动将是我们启动优化中必须攻克的主要难题。并且随着我们贝壳业务的快速发展，各种复杂业务的铺设会加剧冷启动耗时长的问题。Part 3贝壳方法耗时统计工具在进行冷启动优化时，找出耗时点和耗时方法往往是最花时间的，开发者都希望能有一个直观且方便的工具来帮助快速的定位到耗时点。为此我们首先对现有分析工具进行了调研。1.3.1 Android profiler traceviewAndroid TraceView 是官方SDK提供的一个获取trace的一个工具，这个能记录某个时段，App运行时所有的方法栈调用。功能强大。原理是在Jvm层设置方法调用监控实现的。其优点：功能丰富，支持查看cpu耗时和方法耗时、以及方法调用栈等信息支持通过Debug类中提供的api来开始或停止方法调用栈的追踪支持所有线程的方法栈调用记录，并且可以通过profiler进行线程筛选虽然其功能强大并且支持到了Android2.1的系统，但是因为其原理的限制，导致其性能问题一直备受诟病，以下是我们在调研后得知此工具存在的一些问题：通过其Debug类提供的api来指定区间过大时无法生成对应的trace其对启动性能的额外开销达到了500%，这个开销导致其产生的trace信息不具有太高的可信度在生成trace后，使用Android Studio 4.0版本的profiler打开文件时会出现解析失败，无法查看信息的情况就以上的优缺点对比之后，虽然traceview的功能强大且内容丰富，但其存在的性能和使用问题导致我们无法正常使用，最终放弃。1.3.2 Android systraceSystrace是分析Android性能问题的神器，Google IO 2017大会上更是对其各种强推；由于TraceView过于严重的运行时开销，预计Google会放弃TraceView转向全力支持Systrace；不过这个工具并不像TraceView那样简单直观，使用起来也不太方便，而且没有一个详尽的文档介绍如何使用和分析。在介绍使用之前，先简单说明一下Systrace的原理：它的思想很朴素，在系统的一些关键链路（比如System Service，虚拟机，Binder驱动）插入一些信息（我这里称之为Label），通过Label的开始和结束来确定某个核心过程的执行时间，然后把这些Label信息收集起来得到系统关键路径的运行时间信息，进而得到整个系统的运行性能信息。Android Framework里面一些重要的模块都插入了Label信息（Java层的通过android.os.Trace类完成，native层通过ATrace宏完成），用户App中可以添加自定义的Label，这样就组成了一个完成的性能分析系统。其具有以下优点：因为原理是针对关键链路进行监控，所以性能开销很低支持设置监控关键链路的参数，更精确的监控指定链路支持自定义Trace Label用来划分特定监控区域其缺点如下：因其原理改变所以其仅适用于对关键资源的分析，如CPU资源的使用等。并且不会提供完整的方法调用栈，无法对方法层面上进行耗时统计其自定义的标签在部分手机上不生效且存在一定误差其提供的信息较少，展示不够直观。使用上也较为复杂。1.3.3 人为打点因为Android提供的一些工具存在一系列性能或使用上的问题，所以还是有很多的开发者选择人为打点来统计特定方法耗时。这种办法的特点是精度高但效率低。需要人为的找到打点的位置，在统计范围过广时不具有可行性。1.3.4 插桩打点面对人为打点效率低下的问题时，网上很多开发者提供了插桩打点的工具来实现自动化打点，但插桩插件是不会自行决定插桩区域的，需要开发者指定插桩的区域。这样的设定就导致其无法支持获取某一时段内所有的方法调用信息。除此之外网上提供的自动化打点工具都只是提供单个方法的耗时信息，并不能直观的看出方法调用栈，无法处理方法与方法之间的关系。1.3.5 自定义方法统计工具针对以上各种工具的优点以及缺点并结合我们目前的现状，我们列出了目前我们对方法统计工具的需求，如下：快速：运行快速且不产生较大的性能开销直观：直观的展示耗时信息和方法调用栈支持对全部业务方法的打点统计支持配置过滤文件来跳过对应方法的插桩支持仅对单一线程的耗时记录支持全部线程的耗时记录支持统计拦截器，更精细化的耗时统计支持方法耗时的可视化展示支持自定义统计区间根据以上的需求，我们最终采取了ASM插桩+模拟方法调用栈的方案来实现我们所需要的方法耗时统计工具。工具的设计与实现Part 1工具设计综合现有工具的思路和我们对方法耗时统计工具的需求，最终使用的方案是ASM插桩和模拟方法调用栈的方式，首先使用的就是ASM框架来支撑统计代码的插入，大致思路就是在每个方法的前后插入工具方法，并在工具方法中进行数据收集。收集方法的顺序则是方法调用的顺序，然后利用Stack模拟方法的调用，关联上每个方法的开始和结束以及parent节点即可。2.1.1 方法调用信息收集通过ASM框架在每个方法的开头注入recordMethodStart并且在每个方法的结束注入recordMethodEnd。以此来统计方法的调用信息，因为每个存储方法调用信息的队列是线程私有的，所以队列的存储顺序就是此线程中调用方法的执行顺序。处理流程如下图所示：2.1.2 模拟方法调用栈因为JVM对方法的调用是通过栈来实现的，所以只需要按照栈的特性，根据收集方法时的添加顺序反向进行还原即可得出完整的调用链路。处理流程如下图所示：Part 2ASM因为此工具需要使用ASM框架进行插桩，所以先简要介绍一下ASM框架。ASM是一种通用Java字节码操作和分析框架。它可以用于修改现有的class文件或动态生成class文件。用来在目标程序运行过程中获取某些程序状态或信息并加以分析处理以达到一个AOP的效果。大致流程如下图所示：结合Android的打包流程，在Java的编译器将源代码编译成.class文件之后会调用Gradle中注册的transfrom进行字节码的处理，此时也是ASM开始执行的时机，可动态的对类或方法进行增删改等操作，在所有的transfrom都处理完之后就会进行merge jar等一系列操作最终得到.dex文件。如果需要加深对ASM的理解和应用，需要开发者更熟练的学习和掌握class字节码和JVM基于栈的设计模式以及JVM指令等相关知识。Part 3插入统计方法借助ASM中的AdviceAdapter类提供onMethodEnter和onMethodExit方法，我们可以很简单快速的实现对方法开始和方法结束处插入收集代码的功能。实现代码如下所示：overridefunonMethodEnter(){super.onMethodEnter()if(filterSet.contains(className+methodName+desc)){return}mv.visitLdcInsn(className)mv.visitLdcInsn(methodName)mv.visitLdcInsn(desc)mv.visitMethodInsn(INVOKESTATIC,METHOD_RECORD_PATH,"recordMethodStart","(Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)V",false)}overridefunonMethodExit(opcode:Int){super.onMethodExit(opcode)if(!filterSet.contains(className+methodName+desc)){mv.visitLdcInsn(className)mv.visitLdcInsn(methodName)mv.visitLdcInsn(desc)mv.visitMethodInsn(INVOKESTATIC,METHOD_RECORD_PATH,"recordMethodEnd","(Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)V",false)}}对比方法插入前与方法插入后代码如下所示，插入前：publicvoidsendLoadPageRequest(booleanpullRefresh,HttpCallcall){if(call==null){return;}if(pullRefresh){sendRequest(REQUEST_CODE_PULL_REFRESH,call);}else{sendRequest(REQUEST_CODE_GET_MORE_DATA,call);}}插入后：publicvoidsendLoadPageRequest(booleanpullRefresh,HttpCallcall){MethodRecordManager.recordMethodStart("com/bk/mvp/BKListPresenter","sendLoadPageRequest","(ZLcom/lianjia/httpservice/adapter/callAdapter/HttpCall;)V");if(call==null){MethodRecordManager.recordMethodEnd("com/bk/mvp/BKListPresenter","sendLoadPageRequest","(ZLcom/lianjia/httpservice/adapter/callAdapter/HttpCall;)V");return;}if(pullRefresh){sendRequest(REQUEST_CODE_PULL_REFRESH,call);}else{sendRequest(REQUEST_CODE_GET_MORE_DATA,call);}MethodRecordManager.recordMethodEnd("com/bk/mvp/BKListPresenter","sendLoadPageRequest","(ZLcom/lianjia/httpservice/adapter/callAdapter/HttpCall;)V");}从代码中可以看出我们在方法进入的回调处插入了recordMethodStart方法并且传入了className和methodName以及desc,这里传入的三个参数是用来保证方法的唯一性。用于与onMethodExit中调用的recordMethodEnd方法对应上。这里除了进行代码的插入，还进行了一个过滤操作对存储在filterSet的方法信息进行过滤不进行插桩。并且用户可以通过在build.gradle中配置methodRecorder参数中的filterFilePath用于指定过滤文件,代码如下所示：methodRecorder{reocrderClass="com.beike.launch.method.MethodRecordManager"filterFilePath="/Users/xxx/workspace/filter.txt"}过滤文件配置规则是将过滤方法的className以及methodName和desc组成的一行字符串放入即可，一行则表示一个过滤方法。然后在插件执行前会进行过滤文件的读取并添加如filterSet用来保证跳过过滤方法不进行耗时统计。publicfuninitConfig(className:String,filePath:String){className.let{CuckooMethodVisitor.METHOD_RECORD_PATH=it.replace(".","/")}filePath.let{_->valfilterList=File(filePath).readLines()filterList.forEach{CuckooMethodVisitor.filterSet.add(it.trim())}valrealFilter=StringBuilder()CuckooMethodVisitor.filterSet.forEach{realFilter.append(it).append("\n")}File(filePath).writeText(realFilter.toString())}CuckooWeaver.logger.info("className${CuckooMethodVisitor.METHOD_RECORD_PATH}filtercount{CuckooMethodVisitor.filterSet.size}")}Part 4收集方法调用信息在通过ASM插入工具方法后，APP启动时每调用一个方法都会回调如下所示的方法中：publicstaticvoidrecordMethodStart(StringclassName,StringmethodName,Stringdesc){if(!isRunning||(interceptor!=null&interceptor.onMethodIntercept(className,methodName,desc))){return;}finalMethodRecordMessageDatadata=newMethodRecordMessageData(className,methodName,desc,System.currentTimeMillis(),true);recordCollector.collectMethodInfo(data);}publicstaticvoidrecordMethodEnd(StringclassName,StringmethodName,Stringdesc){if(!isRunning||(interceptor!=null&interceptor.onMethodIntercept(className,methodName,desc))){return;}finalMethodRecordMessageDatadata=newMethodRecordMessageData(className,methodName,desc,System.currentTimeMillis(),false);recordCollector.collectMethodInfo(data);}在收集方法中首先进行收集条件的判断，即判断当前是否还处于收集状态中和拦截者是否拦截此次方法收集，如果处于可收集状态中并且拦截器不拦截此次方法收集，即可进行真实的方法调用信息收集。方法的收集由IMethodRecordCollector来实现，其实现类代码如下：@NoMethodRecordpublicclassMethodRecordCollectorimplementsIMethodRecordCollector{privatefinalList>mRecordList=newArrayList(10);privatestaticfinalThreadLocalcollectorLocal=newThreadLocal();@OverridepublicList>getRecordList(){returnthis.mRecordList;}@OverridepublicvoidcollectMethodInfo(MethodRecordMessageDatadata){ThreadLocalCollectorcollector=collectorLocal.get();if(collector==null){collector=newThreadLocalCollector();collectorLocal.set(collector);synchronized(mRecordList){mRecordList.add(collector.getList());}}data.setThreadName(collector.getThreadName());collector.getList().add(data);}@OverridepublicvoidresetRecordList(){for(ListmethodRecordMessageDataList:mRecordList){methodRecordMessageDataList.clear();}this.mRecordList.clear();}@NoMethodRecordprivatestaticclassThreadLocalCollector{privateStringthreadName;privateListlist;publicThreadLocalCollector(){this.threadName=Thread.currentThread().toString();this.list=newLinkedList();}publicStringgetThreadName(){returnthreadName;}publicListgetList(){returnlist;}}}大致原理为通过ThreadLocal为每个Thread维护一个ThreadLocalCollector对象，用于收集对应线程的方法调用信息。在整个方法收集流程中，为了快速且不阻塞方法的执行，工具仅收集了基础的标记信息和时间戳信息。用于后期的还原解析，正是这样的设计思路也是保证程序的性能要求。除此之外，还提供了方法收集拦截器。此拦截器可以提供更精细化的拦截策略，比如冷启动中，主线程的耗时才是真正影响整个冷启动时长的源头，为此我们可以设置一个拦截器，仅收集主线程中的方法调用，实现如下所示：@NoMethodRecordpublicclassMainThreadMethodInterceptorimplementsIMethodRecordInterceptor{privatestaticfinalLoopermainLooper=Looper.getMainLooper();@OverridepublicbooleanonMethodIntercept(StringclassName,StringmethodName,Stringdesc){returnLooper.myLooper()==null||Looper.myLooper()!=mainLooper;}}这样设置方法拦截器后，冷启动就只会收集主线程中方法的调用信息。不仅排除了其他线程的干扰还间接的提升了方法收集的效率。为了最大程度保证方法收集的高效和真实性，还提供了一个方法用于输出方法调用次数超出限制次数的方法，代码如下所示。调用此方法可以输出超出限制次数的方法信息，与之前插件所设计的过滤规则搭配使用，可过滤掉一批频繁调用的方法，提升收集效率，这样设计的原因主要是为了避免类似于json解析时大量的低耗时递归调用，这类方法的运行时长几乎可以忽略，只要收集到其父类的调用时间即可。对其进行过滤可以大大提升方法收集的效率。publicstaticvoidendMethodRecordWithMethodCallCount(intmaxCallCount){endMethodRecord();MethodCallFilterRecorder.debugMethodCallCount(recordCollector.getRecordList(),maxCallCount);}在endMethodRecordWithMethodCallCount执行后会通过Log输出相关超出调用限制次数的方法信息，可通过如下的shell命令进行重定向输入过滤配置文件中。从而保证下次运行插桩时能跳过掉频繁调用的方法。adblogcat-c&adblogcat|grep-i"MethodCallFilterRecorder"|cut-d":"-f4|>>./filter.txtPart 5处理方法调用信息在收集完方法调用后就是方法的还原聚合的过程，按照之前的设计流程，实现代码如下：@OverridepublicvoidrecordMethodStart(MethodRecordMessageDatamessageData){finalMethodRecordBeanparent=mMethodStack.isEmpty()null:mMethodStack.peek();finalStringbeanId=mThreadName+"#"+(++mMethodCount);if(parent!=null)parent.addChild(beanId);mMethodStack.push(newMethodRecordBean(beanId,parent==nullnull:parent.getId(),messageData,mMethodStack.size()));}@OverridepublicvoidrecordMethodEnd(finalMethodRecordMessageDatamessageData){MethodRecordBeanmethodStartBean=mMethodStack.pop();//验证是否pop的StartBean与EndBean为同一方法的统计数据if(!methodStartBean.verification(messageData)){//如果上一次的方法结束回调与此回调属于同一方法则表明方法回调了两次结束//throw和finally各一次，所以忽略第二次方法结束回调，将数据重新入栈if(this.mLastEndBean.verification(messageData)){mMethodStack.push(methodStartBean);return;}//反之由于方法使用了throws，导致方法不能正常退出//从而`mMethodStack`中push了许多无用startBeanwhile(!methodStartBean.verification(messageData)){if(mMethodStack.isEmpty()){thrownewEmptyStackException();}methodStartBean=mMethodStack.pop();}}recordMethodBean(methodStartBean,messageData.getTime());}细心的读者可能会发现这里与之前设计的流程相比会有一些偏差，多了一个验证的环节，这个验证是为了保证程序的走向能符合之前的设计要求，如果某次pop出来的对象与当前方法结束的对象不属于同一方法所发出的记录，则会导致记录的时间出错，继而失去数据记录的真实性。为了保证数据的真实性，必须有一个数据验证的流程，在最初的实现中数据验证不通过则会抛出异常，但在分析异常之后发现，在某些情况下方法的记录顺序会跟我们之前所构思的不一样。主要是以下两类问题所导致的：- throw 与 finally同时调用方法结束如下图反编译后的字节码所示，这里在throw和finally两处地方调用了recordMethodEnd,当触发throw时就会导致连续两次回调recordMethodEnd，破坏方法记录的顺序，为此，使用了一个mLastEndBean来记录上一次完成方法收集的对象，如果再次触发recordMethodEnd则忽略本次的方法结束回调。- throws 导致recordMethodEnd回调丢失如果一个方法被标记了throws，则在此方法发生异常时，将直接中断运行调用上级的catch方法，这样就会导致原本插入在方法底部的recordMethodEnd，不能被及时回调，从而破坏方法的记录顺序，对于此类问题，采取丢弃方法，即当当前方法结束回调与栈顶不属于同一方法且与上一次结束回调的方法也不属于同类方法时，进行退栈，丢弃发生异常的方法，保持原有方法记录的顺序。这样即可解决绝大多数问题，但是对于一类特殊的方法会失效。因为这个丢弃方法的方式，需要对其添加try catch的调用上级方法也进行方法记录。否则会收不到这一系列调用的终止回调，会导致这些“坏死元素”存留在栈中，不过目前仅仅发现了一个场景，可以通过人为过滤解决。即LjPluginClassLoader的loadClass和findClass方法，其解压后的字节码如下图所示，因为这两个方法由系统调用无法监听到系统调用的结束回调，从而导致元素“坏死”。Part 6方法耗时统计可视化在进行了充足的方法调用信息收集后，让方法耗时统计可视化成为了可能，方法耗时统计可视化提供了三个页面展示，分别是线程耗时统计页面、方法耗时统计页面以及方法调用栈展示页面。2.6.1 线程耗时统计页面之前就有说过，此工具支持多线程方法统计，为此需要一个页面展示某个时间段内各个线程的实际耗时情况,并且支持点击查看线程中的方法耗时情况，即进入对应线程的方法统计耗时页面。其页面如下所示：2.6.2 方法统计耗时页面此页面主要为展示某个线程的方法调用耗时信息或某个方法中全部子方法的调用耗时信息，支持按照调用顺序展示或按照耗时排列展示，点击当前方法的item可进入方法调用栈信息进行调用链路的展示。页面如下所示：2.6.3 方法调用栈页面此页面主要用于展示某个方法调用链路。页面如下所示：使用示例以下是在贝壳APP中实际使用时所解决的问题示例：Part 1定位成功后获取城市配置耗时过长问题通过我们的方法耗时统计工具，发现了在开启定位启动App时，有机率在渲染之前触发定位成功的回调，此回调会在主线程中获取全部城市的配置信息。导致主线程被IO阻塞，后续可将其进行优化或延至首帧渲染后进行处理。Part 2贝壳冷启动InitData接口数据处理耗时过长贝壳App在启动时会进行initData接口的请求，此接口返回的数据过于庞大，并且会在主线程中进行数据同步缓存，导致主线程被IO所阻塞，后续将改为异步处理，提升冷启动速度。小结在完成了方法耗时统计工具的实现后，我们将其使用到了贝壳冷启动优化和页面加载耗时优化的工作中，并且利用其直观可靠的特点找出了许多的耗时方法，并且在实际使用中，此工具所产生的额外性能开销保持在10%以下。足够保证数据的可靠性并间接的保证了我们优化方向的正确性。目前此方法耗时统计工具已单独抽离成SDK，待后续完善优化后，可接入其他App中进行使用。此方法耗时统计工具只是贝壳Top Experience项目中的一个开门砖，后续贝壳移动客户端将致力于打造高体验建设平台-雪豹 ，此平台将针对 快、小、稳、省、安这五大方面进行大力建设，并且沉淀出相关技术方案、文档以及辅助工具，用于帮助贝壳和其他App快速提升整体使用效果。后续篇章已经在路上了，敬请期待！也欢迎大家多多留言，交流性能优化的相关经验。 预览时标签不可点 移动端37大前端69移动端 · 目录#移动端上一篇如何玩转Flutter动画下一篇Flutter UI自动化原理与实践关闭更多小程序广告搜索「undefined」网络结果