Android应用快速定位耗时方法

启动耗时检测

查看Logcat

在Android Studio Logcat中过滤关键字“Displayed”,可以看到对应的冷启动耗时日志。

adb shell

使用adb shell获取应用的启动时间

adb shell am start -W [packageName]/[AppstartActivity全路径]

执行后会得到三个时间:ThisTime、TotalTime和WaitTime,详情如下:

  • ThisTime最后一个Activity启动耗时
  • TotalTime所有Activity启动耗时
  • WaitTimeAMS启动Activity的总耗时

一般查看得到的TotalTime,即应用的启动时间,包括创建进程 + Application初始化 + Activity初始化到界面显示的过程。特点:

  • 线下使用方便,不能带到线上。
  • 非严谨、精确时间。

AOP(Aspect Oriented Programming)打点

面向切面编程,通过预编译和运行期动态代理实现程序功能统一维护的一种技术。作用利用AOP可以对业务逻辑的各个部分进行隔离,从而使得业务逻辑各部分之间的耦合性降低,提高程序的可重用性,同时大大提高了开发效率。AOP核心概念1)横切关注点对哪些方法进行拦截,拦截后怎么处理。2)切面(Aspect)类是对物体特征的抽象,切面就是对横切关注点的抽象。3)连接点(JoinPoint)被拦截到的点(方法、字段、构造器)。4)切入点(PointCut)对JoinPoint进行拦截的定义。5)通知(Advice)拦截到JoinPoint后要执行的代码,分为前置、后置、环绕三种类型。首先,为了在Android使用AOP埋点需要引入AspectJ,在项目根目录的build.gradle下加入:

classpath 'com.hujiang.aspectjx:gradle-android-plugin- aspectjx:2.0.0'

然后,在app目录下的build.gradle下加入:

apply plugin: 'android-aspectjx'
implement 'org.aspectj:aspectjrt:1.8.+'

AOP埋点实战JoinPoint一般定位在如下位置:

  • 函数调用
  • 获取、设置变量
  • 类初始化 使用PointCut对我们指定的连接点进行拦截,通过Advice,就可以拦截到JoinPoint后要执行的代码。Advice通常有以下几种类型:
  • Before:PointCut之前执行
  • After:PointCut之后执行
  • Around:PointCut之前、之后分别执行

首先,我们举一个小栗子:

@Before("execution(* android.app.Activity.on**(..))")
public void onActivityCalled(JoinPoint joinPoint) throws Throwable {
...
}

在execution中的是一个匹配规则,第一个*代表匹配任意的方法返回值,后面的语法代码匹配所有Activity中on开头的方法。处理Join Point的类型:

  • call:插入在函数体里面
  • execution:插入在函数体外面

如何统计Application中的所有方法耗时?

@Aspect
public class ApplicationAop {
    @Around("call (* com.json.chao.application.BaseApplication.**(..))")
    public void getTime(ProceedingJoinPoint joinPoint) {
    Signature signature = joinPoint.getSignature();
    String name = signature.toShortString();
    long time = System.currentTimeMillis();
    try {
        joinPoint.proceed();
    } catch (Throwable throwable) {
        throwable.printStackTrace();
    }
    Log.i(TAG, name + " cost" +     (System.currentTimeMillis() - time));
    }
}

注意当Action为Before、After时,方法入参为JoinPoint。当Action为Around时,方法入参为ProceedingPoint。Around和Before、After的最大区别:ProceedingPoint不同于JoinPoint,其提供了proceed方法执行目标方法。总结AOP特性:

  • 无侵入性
  • 修改方便

强烈推荐结合第三节讲解的Systrace工具使用,可以非常快速地定位到耗时方法,上线的时候,可以考虑屏蔽掉AOP功能。

//apply plugin: 'android-aspectjx'

启动速度分析工具TraceView

使用方式

方式1

检测开始代码处添加:

Debug.startMethodTracing();

检测结束代码处添加:

Debug.stopMethodTracing();

使用adb pull将生成的**.trace文件导出到电脑,然后使用Android Studio的Profiler加载。

方式2

打开Profiler -> CPU -> 点击 Record -> 点击 Stop -> 查看Profiler下方Top Down/Bottom Up 区域找出耗时的热点方法。

Profile CPU

1、Trace types
Trace Java Methods会记录每个方法的时间、CPU信息。对运行时性能影响较大。

Sample Java Methods
相比于Trace Java Methods会记录每个方法的时间、CPU信息,它会在应用的Java代码执行期间频繁捕获应用的调用堆栈,对运行时性能的影响比较小,能够记录更大的数据区域。

Sample C/C++ Functions
需部署到Android 8.0及以上设备,内部使用simpleperf跟踪应用的native代码,也可以命令行使用simpleperf。

Trace System Calls
检查应用与系统资源的交互情况。查看所有核心的CPU瓶。内部采用systrace,也可以使用systrace命令。

2、Event timeline
显示应用程序中在其生命周期中转换不同状态的活动,如用户交互、屏幕旋转事件等。

3、CPU timeline
显示应用程序实时CPU使用率、其它进程实时CPU使用率、应用程序使用的线程总数。

4、Thread activity timeline
列出应用程序进程中的每个线程,并使用了不同的颜色在其时间轴上指示其活动。
绿色:线程处于活动状态或准备好使用CPU。
黄色:线程正等待IO操作。
灰色:(重要) 线程正在睡眠,不消耗CPU时间。

Profile提供的检查跟踪数据窗口有四种:

1、Call Chart

提供函数跟踪数据的图形表示形式。
水平轴:表示调用的时间段和时间。垂直轴:显示被调用方。橙色:系统API。绿色:应用自有方法 蓝色:第三方API(包括Java API) 提示:右键点击Jump to source跳转至指定函数。

Call Chart 是 Traceview 和 systrace 默认使用的展示方式。它按照应用程序的函数执行顺序来展示,适合用于分析整个流程的调用。举一个最简单的例子,A 函数调用 B 函数,B 函数调用 C 函数,循环三次,就得到了下面的 Call Chart。

image.png

2、Flame Chart

将具有相同调用方顺序的完全相同的方法收集起来。
水平轴:执行每个方法的相对时间量。垂直轴:显示被调用方。注意:看顶层的哪个函数占据的宽度最大(平顶),可能存在性能问题。
Flame Chart 也就是大名鼎鼎的火焰图。它跟 Call Chart 不同的是,Flame Chart 以一个全局的视野来看待一段时间的调用分布,它就像给应用程序拍 X 光片,可以很自然地把时间和空间两个维度上的信息融合在一张图上。上面函数调用的例子,换成火焰图的展示结果如下。

image.png

当我们不想知道应用程序的整个调用流程,只想直观看出哪些代码路径花费的 CPU 时间较多时,火焰图就是一个非常好的选择。例如,之前我的一个反序列化实现非常耗时,通过火焰图发现耗时最多的是大量 Java 字符串的创建和拷贝,通过将核心实现转为 Native,最终使性能提升了很多倍。

3、Top Down

递归调用列表,提供self、children、total时间和比率来表示被调用的函数信息。Flame Chart是Top Down列表数据的图形化。

4、Bottom Up

展开函数会显示其调用方。按照消耗CPU时间由多到少的顺序对函数排序。注意点:Wall Clock Time:程序执行时间。Thread Time:CPU执行的时间。

TraceView小结

特点

  • 图形的形式展示执行时间、调用栈等。
  • 信息全面,包含所有线程。
  • 运行时开销严重,整体都会变慢,得出的结果并不真实。
  • 找到最耗费时间的路径:Flame Chart、Top Down。
  • 找到最耗费时间的节点:Bottom Up。

作用主要做热点分析,得到两种数据:

  • 单次执行最耗时的方法。
  • 执行次数最多的方法。

启动速度分析工具SysTrace

使用方式:代码插桩

定义Trace静态工厂类,将Trace.begainSection(),Trace.endSection()封装成i、o方法,然后再在想要分析的方法前后进行插桩即可。在命令行下执行systrace.py脚本:

python /Users/quchao/Library/Android/sdk/platform-tools/systrace/systrace.py -t 20 sched gfx view wm am app webview -a "com.wanandroid.json.chao" -o ~/Documents/open-project/systrace_data/wanandroid_start_1.html

具体参数含义如下:

  • -t:指定统计时间为20s。
  • shced:cpu调度信息。
  • gfx:图形信息。
  • view:视图。
  • wm:窗口管理。
  • am:活动管理。
  • app:应用信息。
  • webview:webview信息。
  • -a:指定目标应用程序的包名。
  • -o:生成的systrace.html文件。

如何查看数据?

在UIThread一栏可以看到核心的系统方法时间区域和我们自己使用代码插桩捕获的方法时间区域。

Systrace原理

在系统的一些关键链路(如SystemServcie、虚拟机、Binder驱动)插入一些信息(Label); 通过Label的开始和结束来确定某个核心过程的执行时间; 把这些Label信息收集起来得到系统关键路径的运行时间信息,最后得到整个系统的运行性能信息; Android Framework里面一些重要的模块都插入了label信息,用户App中可以添加自定义的Lable。

Systrace小结

特性
结合Android内核的数据,生成Html报告。系统版本越高,Android Framework中添加的系统可用Label就越多,能够支持和分析的系统模块也就越多。必须手动缩小范围,会帮助你加速收敛问题的分析过程,进而快速地定位和解决问题。作用主要用于分析绘制性能方面的问题。分析系统关键方法和应用方法耗时。

结合AOP,可以在方法的前后,非常方便地批量插入以下代码。最后从运行生成Html报告后,可以快速查找出耗时的方法。

Trace.begainSection();
//your code
Trace.endSection();

总结

Traceview 和 systrace 都是我们比较常用的排查卡顿的工具,从实现上这些工具分为两个流派。
第一个流派是 instrument。获取一段时间内所有函数的调用过程,可以通过分析这段时间内的函数调用流程,再进一步分析待优化的点。
第二个流派是 sample。有选择性或者采用抽样的方式观察某些函数调用过程,可以通过这些有限的信息推测出流程中的可疑点,然后再继续细化分析。

Traceview

Traceview是吐槽的比较多的工具。它利用 Android Runtime 函数调用的 event 事件,将函数运行的耗时和调用关系写入 trace 文件中。

由此可见,Traceview 属于 instrument 类型,它可以用来查看整个过程有哪些函数调用,但是工具本身带来的性能开销过大,有时无法反映真实的情况。比如一个函数本身的耗时是 1 秒,开启 Traceview 后可能会变成 5 秒,而且这些函数的耗时变化并不是成比例放大。

在 Android 5.0 之后,新增了startMethodTracingSampling方法,可以使用基于样本的方式进行分析,以减少分析对运行时的性能影响。新增了 sample 类型后,就需要我们在开销和信息丰富度之间做好权衡。

systrace

systrace是 Android 4.1 新增的性能分析工具。我通常使用 systrace 跟踪系统的 I/O 操作、CPU 负载、Surface 渲染、GC 等事件。systrace 利用了 Linux 的ftrace调试工具,相当于在系统各个关键位置都添加了一些性能探针,也就是在代码里加了一些性能监控的埋点。Android 在 ftrace 的基础上封装了atrace,并增加了更多特有的探针,例如 Graphics、Activity Manager、Dalvik VM、System Server 等。systrace 工具只能监控特定系统调用的耗时情况,所以它是属于 sample 类型,而且性能开销非常低。但是它不支持应用程序代码的耗时分析,所以在使用时有一些局限性。由于系统预留了Trace.beginSection接口来监听应用程序的调用耗时,那我们有没有办法在 systrace 上面自动增加应用程序的耗时分析呢?

划重点了,我们可以通过编译时给每个函数AOP插桩的方式来实现,也就是在重要函数的入口和出口分别增加Trace.beginSection和Trace.endSection。当然出于性能的考虑,我们会过滤大部分指令数比较少的函数,这样就实现了在 systrace 基础上增加应用程序耗时的监控。

通过这样方式的好处有:
可以看到整个流程系统和应用程序的调用流程。包括系统关键线程的函数调用,例如渲染耗时、线程锁,GC 耗时等。性能损耗可以接受。由于过滤了大部分的短函数,而且没有放大 I/O,所以整个运行耗时不到原来的两倍,基本可以反映真实情况。

Profiler

在 Android Studio 3.2 的 Profiler 中直接集成了几种性能分析工具,其中:

  • Sample Java Methods 的功能类似于 Traceview 的 sample 类型。
  • Trace Java Methods 的功能类似于 Traceview 的 instrument 类型。
  • Trace System Calls 的功能类似于 systrace。
  • SampleNative (API Level 26+) 的功能类似于 Simpleperf,用来分析Native方法耗时。
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 218,204评论 6 506
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 93,091评论 3 395
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 164,548评论 0 354
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,657评论 1 293
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,689评论 6 392
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,554评论 1 305
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,302评论 3 418
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,216评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,661评论 1 314
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,851评论 3 336
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,977评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,697评论 5 347
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,306评论 3 330
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,898评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,019评论 1 270
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,138评论 3 370
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,927评论 2 355

推荐阅读更多精彩内容

  • 前言 性能优化的过程分两部分: 发现性能瓶颈 制定方案,解决性能问题 解决性能问题的方案需要具体情况具体分析,并没...
    未子涵阅读 2,357评论 0 51
  • 讲师五期分享691天 星期五 阴 2019.4.25 下午快下班的时候,接到了丰老师发来的微信,急忙参与晚上...
    追逐梦的自由阅读 80评论 0 1
  • 日语的动词变形规律非常复杂,对于各位初学者来说一直是语法中的一大难点。 本文编撰的口诀说不定就能帮助你突破这个难关...
    dc3c12c58779阅读 189评论 0 0
  • “爆竹声中一岁除,春风送暖入屠苏”刚学会这句诗,我最喜欢的春节就又到了。 每当春节一到,我就会和爷...
    夏卫英阅读 205评论 0 0
  • 喜欢坐在火车靠窗的位置 因为可以看到 不同的风景 和铁道旁开着白花的灌木 虽然至今也不知道她叫什么名字 喜欢看车上...
    小木兮兮阅读 370评论 0 0