TraceView是什么
TraceView是Android SDK中内置的一个数据采集和分析工具,它可以加载trace文件,用图形的形式展示代码的执行时间、次数及调用栈,找出最需要优化的点。
trace文件是log信息文件的一种,可以通过代码,Android Studio,或者DDMS生成。
TraceView从代码层面分析性能问题,针对每个方法来分析,比如当我们发现我们的应用出现卡顿的时候,我们可以分析出现卡顿时在方法的调用上有没有很耗时的操作,通过TraceView,可以得到两种数据:
- 单次执行最耗时的方法
- 执行次数最多的方法
手机卡顿很多时候都是由于某个操作过于耗时,在茫茫代码中查找元凶未免太过痛苦,这时候就该体现 TraceView 的价值了。
生成trace文件
生成trace文件有三种:
- 使用代码
- 使用DDMS
- 使用Android Studio
使用代码生成trace文件
首先选择跟踪范围,在想要跟踪的代码片段之间使用以下两句代码。
Debug.startMethodTracing("tracefilename"); //开始 trace,保存文件到 "/sdcard/tracefilename.trace"
// ...
Debug.stopMethodTracing(); //结束
当你调用Debug.startMethodTracing()方法的时候,系统会产生trace文件,并且产生追踪数据;调用Debug.stopMethodTracing()方法结束代码时,会将追踪数据写入到trace文件中。
生成的trace文件会自动放在sdcard上,没有sdcard会出现异常,所以使用这种方式需要确保应用的AndroidManifest.xml中的SD卡的读写权限是打开的,其中tracefilename是trace文件的名字。
下一步使用adb命令将trace文件导出到电脑:adb pull /sdcard/tracefilename.trace /tmp
然后启动Android Device Monitor-->File-->openFile,打开traceview文件即可。
使用代码生成trace方式的好处是,容易控制追踪的开始和结束;确定是步骤稍微多了一点。
使用DDMS生成trace文件
DDMS,即Dalvik Debug Monitor Server,是 Android 开发环境中的Dalvik虚拟机调试监控服务。为测试设备截屏,针对特定的进程查看正在运行的线程以及堆信息,查看log,查看试图层级等功能。
在Eclipse中使用DDMS
点击DDMS左侧的Start Method Profiling按钮(具体位置如下图,三个小箭头和红点的那个按钮)。
然后,进行你认为卡顿的界面操作;然后再次点击那个按钮(此时变为Stop Method Profiling),DDMS就会显示出如下图的界面。
在AndroidStudio中使用DDMS
双击 shift 弹出全局搜索,搜索 “Android Device Monitor”:
之后的操作同在Eclipse中相同。
使用Android Studio生成trace文件
Android Studio 内置的 Android Monitor 可以很方便的生成 trace 文件到电脑。在 CPU 监控的那栏会有一个闹钟似的的按钮,未启动应用时是灰色:
启动应用后,这个按钮会变亮,点击后开始追踪,相当于代码调用 startMethodTracing:
当要结束追踪时再次点击这个按钮,就会生成 trace 文件了。生成 trace 后 Android Studio 自动加载的 traceview 图形如下:
从这个图可以大概了解一些方法的执行时间、次数以及调用关系,也可以搜索过滤特定的内容。
左上角可以切换不同的线程,这其实也是直接用 Android Studio 查看 trace 文件的缺点:无法直观地对比不同线程的执行时间。鼠标悬浮到黄色的矩形上,会显示对应方法的开始、结束时间,以及自己占用和调用其他方法占用的时间比例:
TraceView工具面板介绍
上面这个图取自网友的一篇博客中,我在本地查找并没有出现匹配的方法,不知道问啥。
上面是时间轴面板(Timeline Panel)
左侧显示的是线程信息;
右侧黑色部分是显示执行时间段、白色是线程暂停时间段;
右侧鼠标放在上面会出现时间线纵轴,在顶部会显示当前时间线所执行的具体函数信息;
下面是分析面板(Profile Panel)
Includsive time:函数本身运行花费时间+函数调用其他函数时间。
Exclusive time:函数本身运行花费时间。
Calls+RecurCall/Total:调用+重复调用次数/函数总调用次数。
Cpu Time/Call:总的Cpu时间与总的调用次数之比。
Profile Panel各列表作用说明如下表:
表1-1 Profile Panel各列作用说明
列名 | 描述 |
---|---|
Name | 该线程运行过程中所调用的函数名 |
Incl Cpu Time | 某函数占用的CPU时间,包含内部调用其它函数的CPU时间 |
Excl Cpu Time | 某函数占用的CPU时间,但不含内部调用其它函数所占用的CPU时间 |
Incl Real Time | 某函数运行的真实时间(以毫秒为单位),内含调用其它函数所占用的真实时间 |
Excl Real Time | 某函数运行的真实时间(以毫秒为单位),不含调用其它函数所占用的真实时间 |
Call+Recur Calls/Total | 某函数被调用次数以及递归调用占总调用次数的百分比 |
Cpu Time/Call | 某函数调用CPU时间与调用次数的比。相当于该函数消耗CPUDE平均执行时间 |
Real Time/Call | 同CPU Time/Call类似,只不过统计单位换成了真实时间,该函数平均执行时间 |
Incl Cpu Time
Incl Cpu Time表示这个函数从开始被执行到执行结束的时间。这个时间包括这个函数中调用其他函数所花费的时间。也就是说,这个函数和函数中所有子函数一共执行时间。我们看个例子:
public void example() {
a();
b();
}
Incl Cpu Time就表示example函数执行的总时间,假如说example方法执行的时间为10ms,函数a执行了3ms,方法b执行了6ms,调用example方法的函数执行总时间为100ms。最终计算出来的Incl Cpu TIme比率为:
- example 10%
- a 30%
- b 60%(此处怀疑为毛不是6%)
通过这个指标,我们可以看到一个函数的所有时间的占比,这个指标一般不会用到,因为我们一般都先查看所有函数的Excl Cpu Time指标。但是当你需要精确了解各个函数总执行时间并优化时,你还是需要先从这个函数入手。比如说优化应用冷启动时间,这个时候并没有明显的有较长Excl Cpu Time的函数,你需要对目标函数进行一点一点的分析和优化。而不是像寻找明显卡顿原因时的直接找Excl Cpu TIme指标最大的函数。
Excl Cpu Time
还是看上面那个例子,我们可以计算出各个函数的Incl Cpu Time比例。
- example (10-3-6)/100=1%
- a 30%
- b 60%
从例子上可以看出,一个方法的Excl Cpu TIme等于它的Incl Cpu TIme减去它所有子函数的Incl Cpu Time。
Incl Real Time和Excl Real Time
对这两条指标的理解主要涉及到对Cpu time和Real time的理解。Cpu Time应该是某个方法占用CPU的时间;而Real Time应该是这个方法的实际运行时间。因为Cpu的上下文切换、阻塞、等待等原因,Real Time一般长于Cpu Time。
Calls+Recur Calls/Total
这个指标表示这个方法执行的总次数。Calls表示这个函数的调用次数,Recur Calls表示递归调用次数。
Cpu Time/Calls和Real Time/Calls
这两个指标表示方法的每次调用的平均执行时间。
开发者最关心的数据有:
很重要的指标:Calls + Recur Calls/Total,最重要的指标:Cpu Time/Call
因为我们最关心的有两点,一是调用次数不多,但每次调用却需要花费很长时间的函数,这个可以从Cpu Time/Call反映出来。另外一个是那些自身占用时间不长,但调用却非常频繁的函数,这个可以从Calls + Recur Calls/Total 反映出来。
例证
下面写一个DEMO,来分别模拟调用次数不多,但每次调用却需要花费很长时间的函数,和自身占用时间不长,但调用却非常频繁的函数。
package sgf.com.traceview;
import android.os.Bundle;
import android.support.v7.app.AppCompatActivity;
import android.util.Log;
public class MainActivity extends AppCompatActivity {
int count = 0;
long longCount = -1;
@Override
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
// Debug.startMethodTracing("hello");
// 线程1
new Thread(new Runnable() {
@Override
public void run() {
printNum();
}
}, "printNum_thread").start();
// 线程2
new Thread(new Runnable() {
@Override
public void run() {
calculate();
}
}, "calculate_thread").start();
}
@Override
protected void onStop() {
super.onStop();
// Debug.stopMethodTracing();
}
@Override
protected void onDestroy() {
super.onDestroy();
}
private void printNum() {
for (int i = 0; i < 20000; i++) {
print();
}
}
/**
* 模拟一个自身占用时间不长,但调用却非常频繁的函数
*/
private void print() {
count = count++;
}
/**
* 模拟一个调用次数不多,但每次调用却需要花费很长时间的函数
*/
private void calculate() {
for (int i = 0; i < 1000; i++) {
for (int j = 0; j < 1000; j++) {
for (int l = 0; l < 1000; l++) {
if (longCount > 10) {
longCount = -10;
}
}
}
}
Log.e("MainActivity", String.valueOf(longCount));
}
}
现在来看一下采集的数据,先看线程面板。
在线程面板上发现我们应用中的三个线程,main线程,这个线程是都会有的,还有printNum_thread,calculate_thread两个线程。
再看时间面板。
时间线面板以每个线程为一行,右边是该线程在整个过程中方法执行的情况,一行中有很多小色块。
这些色块代表采集过程中方法调用时间线,相同颜色代表相同的方法,其中的每一个小色块就代表一次方法的调用,色块的长度代表方法执行时间的长短;左边为第一个色块代表方法执行开始,最右边色块代表最后一个方法执行结束;有时候可以根据色块长度来做个大致判断,哪一个方法执行时间相对来说比较长;
点击Calls + Recur Calls这一栏,可以按照方法调用次数排序;点击Cpu Time / Call这一栏,可以按照方法调用时间排序。
TraceView工具的使用大致介绍到这里。