（转载）Android 耗时代码(ANR)的查找检测和分析解决
原文链接：Android 耗时代码(ANR)的查找检测和分析解决 TraceView的使用手册 - CSDN博客
关于ANR：Application Not Response，意思是应用未能及时响应。
ANR有三种发生情况：
前两者定义在ActivityManagerService.java里面，
屏幕或按键点击后5秒内无响应，
// How long we wait until we timeout on key dispatching.
static final int KEY_DISPATCHING_TIMEOUT = 5*1000;
前台广播10秒内没处理完，后台广播可以60秒没处理完，
// How long we allow a receiver to run before giving up on it.
static final int BROADCAST_FG_TIMEOUT = 10*1000;
static final int BROADCAST_BG_TIMEOUT = 60*1000;
Service的超时定义在ActiveServices.java里，意思是处于前台进程里的服务20秒没处理完超时，处于后台进程里的服务200秒没响应。
// How long we wait for a service to finish executing.
static final int SERVICE_TIMEOUT = 20*1000;
// How long we wait for a service to finish executing.
static final int SERVICE_BACKGROUND_TIMEOUT = SERVICE_TIMEOUT * 10;
对于这个有些解释把前者译为前台服务。我觉得是有歧义的，因为前台服务一般说的是有在通知栏有一个常驻通知的服务。
实测过，写一个普通Service，SystemClock.sleep(20000)会报ANR，SystemClock.sleep(19500)不会报ANR。
出现ANR后，执行adb命令下载日志到某个目录，adb pull /data/anr/traces.txt D:\ss，然后就可以查看ANR出现的地方。
打开这个traces.txt文件，开头会有大概20行的当前应用运行信息。然后是就是ANR出现的代码定位了，
DALVIK THREADS (21):
"main" prio=5 tid=1 Sleeping
| group="main" sCount=1 dsCount=0 obj=0x76af9fb0 self=0x7f9b49a000
| sysTid=4423 nice=0 cgrp=default sched=0/0 handle=0x7f9f6e7e30
| state=S schedstat=( 1089793398 859095826 3028 ) utm=90 stm=18 core=7 HZ=100
| stack=0x7fbff76000-0x7fbff78000 stackSize=8MB
| held mutexes=
at java.lang.Thread.sleep!(Native method)
- sleeping on <0x12b5bd91> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:1031)
- locked <0x12b5bd91> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:985)
at android.os.SystemClock.sleep(SystemClock.java:120)
at com.yao.mytestproject.service.NormalService.onStartCommand(NormalService.java:27)
at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:3293)
at android.app.ActivityThread.access$2200(ActivityThread.java:187)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1688)
at android.os.Handler.dispatchMessage(Handler.java:111)
at android.os.Looper.loop(Looper.java:194)
at android.app.ActivityThread.main(ActivityThread.java:5871)
at java.lang.reflect.Method.invoke!(Native method)
at java.lang.reflect.Method.invoke(Method.java:372)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1119)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:885)
比如这个例子，是因为在NormalService里面SystemClock.slee方法导致的ANR。
Android不止有ANR，还有阻塞操作和耗时代码。
说是屏幕或按键点击后5秒内无响应，但是1,2秒没反应已经让用户挺崩溃了。所以找出应用的耗时代码是一件十分重要的事。
生成TraceView日志的两种方式
第一种是通过代码生成，
开始的地方写代码 Debug.startMethodTracing();
结束的地方写代码 Debug.stopMethodTracing();
注意需要写入sdcard权限。
日志会保存到/sdcard/dmtrace.trace，然后adb pull /sdcard/dmtrace.trace D:\dir拉下来。用Android Device Monitor打开就行。
第二种是通过操作Android Device Monitor的按钮生成，
打开Android Device Monitor，选中想观察的进程。点击Start Method Profiling，一通操作后，再点击Stop method Profiling。就是弹出这段时间操作的trace文件。
强烈建议用这种方式，因为第一种方式有bug。文章后面会介绍。
.trace文件显示是这样的。分为两部分。
.trace文件使用Monitor打开
上半部分是一个图，一行表示一个线程，列表示时间。
鼠标放在图中间的区域，左上角会出现几个信息，分别是毫秒数（millisecond的缩写），当前时刻正在执行的方法以及它的方法编号，以及一些执行时间信息。此时点击可以在使下面表格跳到对应的方法里。
时间轴
拖拽可以放大选中的区域，双击上面的信息栏可以返回原始大小。
拖动操作图
下半部分是一个详细的表格，一行代表一种方法，各个列代表某个执行时间或对应的百分比。具体来说每一项对应的意思，
Incl Cpu Time：某方法占用CPU的时间
Excl Cpu Time：某方法本身（不包含子方法）占用CPU的时间
Incl Real Time：某方法执行所占用执行的时间
Excl Real Time：某方法本身（不包括子方法）执行所占用的时间
Calls+RecurCalls/Total：调用+递归调用某方法的次数（Total只在点击一个方法后展示的详细项才有，代表总方法调用次数）
Cpu Time/Call：表示Incl Cpu Time / Call的时间，即某方法平均占用CPU时间
Real Time/Call：表示Incl Real / Call的时间，即某方法平均执行时间
方法调用堆栈
比如这个表格，我选择了按Incl Real Time倒序排列。
发生这几个方法都只执行了一次，占用了20秒出头。因为我代码中是这么写的
因为Sleep方法执行耗时，但是Cpu并不需要运行，所以Incl Cpu Time很小。
@Override
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_empty);
findViewById(R.id.btn).setOnClickListener(new View.OnClickListener() {
@Override
public void onClick(View v) {
doSomeNetwork();
}
});
}
private void doSomeNetwork() {
SystemClock.sleep(20000);
}
只观察当前包名的方法，可以看到从匿名内部类的onClick方法开始，TraceActivity到access$000（表示为了内部类可以访问外部类的私有方法或变量，Java编译器生成的一种特殊的静态方法），到doSomeNetWork方法，到SystemClock.sleep方法，到Thread.sleep方法执行时间都是20秒出头。并且由于这是包含关系，所以时间是递减的。
而从onClick方法往上看，也能看到我们的点击事件是从dispatchMessage方法开始，到handleCallback.....等等一系列的调用过程。
doSomeNetwork方法
点开某个方法，比如doSomeNetwork来看，会列举出当前方法的父方法和子方法，点击这些父、子方法还能自动跳转，很方便。
一般如何使用这个工具？大概是分两类，一类是找执行时间久的方法，一类是找到调用次数多到不符合常理的方法。
一.执行时间久
主要是观察Incl Real Time，来个实际例子，代码如下，这是一个OkHttp请求后的回调。
@Override
public void onResponse(Call call, Response response) throws IOException {
if (response.isSuccessful()) {
DailiesJson dailiesJson = new Gson().fromJson(response.body().string(), DailiesJson.class);
if (TextUtils.isEmpty(endDate)) { //如果是首次加载这个界面
startDate = dailiesJson.getDate();
endDate = dailiesJson.getDate();
dailyAdapter.addList(dailiesJson.getStories());
getDataComplete(tartgetDate);
} else if (tartgetDate == null) { //表示下拉刷新
if (endDate.equals(dailiesJson.getDate())) { //App的最晚时间 等于 下拉新获取的时间
stopRefreshing();
} else { //App的最晚时间 不等于 下拉新获取的时间
endDate = dailiesJson.getDate();
dailyAdapter.addListToHeader(dailiesJson.getStories());
}
} else { //表示上拉加载
startDate = dailiesJson.getDate();
dailyAdapter.addList(dailiesJson.getStories());
getDataComplete(tartgetDate);
}
}
}
trace文件是这样的，
trace文件
这方法是OkHttp访问url成功后的回调，可以看到里面的Gson.formJson方法在只执行了一次，却耗费了674毫秒。
之后就可以考虑看看是不是应该换个更快更给力的json解析工具比如fastjson，还是跟服务端讨论一下优化返回的json结构减少冗余。或者是把这段解析json的代码放入子线程里面完成以免影响主线程里的UI更新（OkHttp的onResponse默认是放在子线程里面的）。
二.调用次数多到不符合常理
除了执行方法耗时Incl Real Time，另一个需要关注的列是Calls+RecurCalls/Total。查看是不是某些方法多次冗余调用了。
很奇怪的如果是第一种通过代码生成的trace文件，我写了两个demo，RecyclerView.Adapter和ListView的BaseAdapter，里面的属于构建Item视图的onBindViewHolder方法和getView方法都无法正常显示调用次数。onBindViewHolder是完全找不到有这个方法，而getView方法是只显示调用了一次，而我日志打印出来其实getView已经执行了19次。
用了第二种方法就能正常显示了。这里我写了个ListView配BaseAdapter的demo。普通ListView，刚打开没有滑动时候，界面能显示比如6个Item，就是执行6次getView方法。大家都懂。然后对于ScrollView嵌套ListView，有一种解决方式是自定义ListViewForScrollView继承ListView，onMeasure方法里让它的高度一次性测量出来，具体了解看链接 Android开发之ScrollView中嵌套ListView的解决方案。
对于这种ListViewForScrollView，我们也来trace一下看看。
trace文件
发现应用只是刚打开页面，还没滚动这个ScrollView，就已经执行了38次getView。
找到getView方法，发现它只有一个父类方法AbsListView.obtainView。很方便的我们点击它看看。
obtainView() Trace文件
可以看到obtainView方法分别被ListView.makeAndAddView和ListView.measureHeightOfChildren各调用了19次。
具体原因是因为ListViewForScrollView是一下子测量出所有的item的高度并且一次性显示出来的。所以当然性能方面会比较差，这个ListView只有19个item还能忍一忍，item比较多的情况就不应该用这种方案了。
附一个普通且健康的ListView的BaseAdapter.getView的trace表格。可以看到真正执行时间只有72毫秒，是不是比上面的234毫秒快很多。
健康ListView
有一点需要吐槽的，就是TraceView最底下的搜索栏根本不能搜索！！去StackOverFlow一搜，说从2012年发现的bug到现在还没修复。
http://stackoverflow.com/questions/38632495/android-traceview-find-on-traceview-does-not-work
更新：cmd中使用命令行打开的TraceView工具可以用搜索。
只能用命令行，直接点击会显示这个独立的traceview工具已废弃，请使用Android Device Monitor代替。有点醉。
C:\Users\Administrator\AppData\Local\Android\sdk\tools>traceview.bat C:\Users\Administrator\Desktop\dmtrace.trace
还有一种也是可以全局检测是否有耗时操作，比如主线程里有网络访问、磁盘读写的检测方式叫StrictMode。
总结一句就是使用方便，但是功能没有trace多。可以参考文章Android性能调优利器StrictMode。
