Android 如何处理Anr (借用Logcat和Trace 日志)
Posted 新根
tags:
篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了Android 如何处理Anr (借用Logcat和Trace 日志)相关的知识,希望对你有一定的参考价值。
文章目录
1.Anr的基础知识
在开发中,遇到anr 的原因会有:
- 主线程频繁进行耗时的IO操作:如数据库读写
- 多线程操作的死锁,主线程被block;
- 主线程被Binder 对端block;
System Server
中WatchDog出现ANR;service binder
的连接达到上线无法和和System Server通信- 系统资源已耗尽(管道、CPU、IO)
当发生Anr时,系统会记录以下信息:
- 各个进程的cpu使用情况
- cpu的负载
- IO Wait
- traces文件。
接下来,通过一个输入事件没有响应的案例来,借用loagcat和trace 文件 分析。
2.编写一个Anr的案例
通过Studio编写以下代码:(来源网络)
public class MainActivity extends AppCompatActivity
private static final String TAG = "MainActivity";
private TextView testText;
@Override
protected void onCreate(Bundle savedInstanceState)
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
initView();
Log.d(TAG, "onCreate start");
@Override
protected void onPause()
super.onPause();
try
Log.d(TAG, "onPause 准备sleep9秒");
Thread.sleep(9000);
Log.d(TAG, "onPause sleep9秒完成");
catch (InterruptedException e)
e.printStackTrace();
@Override
protected void onStop()
super.onStop();
Log.d(TAG, "onStop start");
try
Log.d(TAG, "onStop 准备sleep9秒");
Thread.sleep(9000);
Log.d(TAG, "onStop sleep9秒完成");
catch (InterruptedException e)
e.printStackTrace();
private void initView()
Button btnTest = findViewById(R.id.btn_test);
testText = findViewById(R.id.tv_test);
btnTest.setOnClickListener(new View.OnClickListener()
@Override
public void onClick(View view)
testSleep();
);
public void testSleep()
//10s之后本应该进行更新ui操作,但是由于此时主线程处于休眠状态,因此待主线程结束休眠之后才会进行更新ui操作
new Handler().postDelayed(new Runnable()
@Override
public void run()
Log.d(TAG, "准备更新text");
testText.setText("update btn text");
Log.d(TAG, "更新text完成");
, 10000);
try
Log.d(TAG, "准备sleep30秒");
Thread.sleep(30000);
Log.d(TAG, "sleep30秒完成");
catch (InterruptedException e)
e.printStackTrace();
Log.d(TAG, "first update");
testText.setText("This is the first update");
点击按钮,滑动屏幕或者点击Back键,等待几秒则会出现anr的弹窗。
3. 借用 logcat日志和trace文件分析Anr
获取logcat的日志文件
当app运行程序的时候,开启命令行。
首先,在打开命令行(未配置adb全路径,请在sdk中打开命令行) 下执行:
adb logcat -b all -v time >.\\anr_test.log
,如下图所示:
解释:
- -b all :抓取全部事件日志
- -v time: 在log中加入每条log发生的时间
- .\\anr_test.log:当前目录下记录日志的文件
发生anr 后,执行Ctrl+c 操作,结束日志抓取。
最终,日志会存储在执行cmd 命令所在目录下的anr_test.log文件中,如下图所示:
接下来,通过编辑器打开anr_test.log日志,寻找logcat的anr事件。
在anr_test.log中检索event log和 system log 事件:
通过event log 检索 am_anr
:
11-02 11:32:16.915 I/am_anr ( 1753): [0,23694,com.miniwan.test.myapplication,820559686,Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 22. Wait queue head age: 5729.4ms.)]
am_anr 的结构格式:[User ,pid ,Package Name,Flags ,reason] 。更多event log的资料,请阅读Android EventLog。
从上可知:
11-02 11:32:16
:是anr发生时间- com.miniwan.test.myapplication:是发生anr程序的包名
- 23694:是发生anr的进程 id
- Input dispatching timed out: 是anr的原因
通过system log , 继续检索ANR in
关键字,能找到进一步更详细的信息:
11-02 11:32:29.407 E/ActivityManager( 1753): ANR in com.miniwan.test.myapplication (com.miniwan.test.myapplication/.MainActivity)
11-02 11:32:29.407 E/ActivityManager( 1753): PID: 23694 //进程id
11-02 11:32:29.407 E/ActivityManager( 1753): Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 22. Wait queue head age: 5729.4ms.) //发生anr的原因,这里是输入事件没有响应
11-02 11:32:29.407 E/ActivityManager( 1753): Parent: com.miniwan.test.myapplication/.MainActivity
11-02 11:32:29.407 E/ActivityManager( 1753): Load: 0.0 / 0.0 / 0.0 //Load表明是1分钟,5分钟,15分钟CPU的负载
11-02 11:32:29.407 E/ActivityManager( 1753): CPU usage from 0ms to 12458ms later (2021-11-02 11:32:16.860 to 2021-11-02 11:32:29.318): // ANR后CPU的使用情况 ======later是标志
11-02 11:32:29.407 E/ActivityManager( 1753): 0.6% 1366/media.codec: 0.4% user + 0.2% kernel / faults: 62207 minor 60 major
11-02 11:32:29.407 E/ActivityManager( 1753): 0.9% 23694/com.miniwan.test.myapplication: 0.5% user + 0.4% kernel / faults: 2693 minor 5 major // 当前进程的cpu 使用情况
//......省略部分日志
11-02 11:32:29.407 E/ActivityManager( 1753): 0.1% 12039/kworker/u17:0-dwc_wq
11-02 11:32:29.407 V/java.lang.ASSERT( 1753): copyAnr filePath = /data/anr/anr_2021-11-02-11-32-17-657 //
从上可知:
-
进程Id为23694且包名为com.miniwan.test.myapplication 的程序发生Anr ,是因为输入事件没有响应导致的。
-
Wait queue length: 22是指前面还有 22个事件等待处理。
-
Load: 0.0 / 0.0 / 0.0 //是指 在 1分钟,5分钟,15分钟CPU的负载。
-
从上面数据看没有IO wait 或者cpu使用不合理的地方。
当找到anr 发生原因,后需要借助trace.txt 进一步分析。
获取Trace.txt 文件
打开cmd命令行,输入adb bugreport
执行。会在命令所在的目录,生成对应的压缩文件。
若是没有生成,则在android studio的Device File Explorer的bugreports目录下看到,再拷贝出来。
根据anr发生的时间点找到对应的bugreport压缩文件。
在bugreport压缩包中,bugreport_xxxx.txt也是可以查看到记录的logcat 事件,和执行adb logcat -b all -v time >.\\anr_test.log
类似,如下图所示:
解压后,在FS/data/anr下找到对应事件的trace日志,如下图所示:
通过编辑器,打开该trace文件,根据进程id(23694)和发生时间点(11-02 11:32:16)找到相应的信息:
----- pid 23694 at 2021-11-02 11:32:17 -----
Cmd line: com.miniwan.test.myapplication //程序的包名
Build fingerprint: 'OPPO/PCLM50/OP4AB5:10/QKQ1.200216.002/1609877348:user/release-keys'
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=9847 post zygote classes=539
//.....省略部分日志
"main" prio=5 tid=1 Sleeping //这里主线程是tid唯一标识为1, sleep是沉睡状态
| group="main" sCount=1 dsCount=0 flags=1 obj=0x71925cf0 self=0x7dc7a10800
| sysTid=23694 nice=-10 cgrp=default sched=0/0 handle=0x7e4decaed8 //主线程的id是和主进程的id一致
| state=S schedstat=( 377724687 71579581 186 ) utm=31 stm=6 core=7 HZ=100
| stack=0x7fc5112000-0x7fc5114000 stackSize=8192KB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x02cd17eb> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:440)
- locked <0x02cd17eb> (a java.lang.Object) //持有0x02cd17eb这个锁,在沉睡
at java.lang.Thread.sleep(Thread.java:356)
at com.miniwan.test.myapplication.MainActivity.testSleep(MainActivity.java:79)
at com.miniwan.test.myapplication.MainActivity$1.onClick(MainActivity.java:58)
at android.view.View.performClick(View.java:7377)
at com.google.android.material.button.MaterialButton.performClick(MaterialButton.java:967)
at android.view.View.performClickInternal(View.java:7339)
at android.view.View.access$3900(View.java:823)
at android.view.View$PerformClick.run(View.java:28258)
at android.os.Handler.handleCallback(Handler.java:883)
at android.os.Handler.dispatchMessage(Handler.java:100)
at android.os.Looper.loop(Looper.java:238)
at android.app.ActivityThread.main(ActivityThread.java:7890)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:983)
根据以上代码走向,最后锁定在MainActivity#testSleep()方法中,持有了锁在沉睡,导致主进程在沉睡。当用户点击back键,系统进程am 通过binder 通信到主进程中,但间隔5秒都没有收到回执,系统进程抛出anr。
归纳总结:
- 当发生anr的时候,首先通过logcat的日志 ,找到event(am_anr)和system(即anr in)的log信息,分析处anr发生原因(IO wait、输入事件没响应、死锁、cpu紧张等等)
- 最后,借助trace 文件,根据进程id,包名等信息,查看当时各个线程代码走向,找到代码问题所在处。
参考:
以上是关于Android 如何处理Anr (借用Logcat和Trace 日志)的主要内容,如果未能解决你的问题,请参考以下文章
Android ANR 分析 /data/anr/trace.txt 该文件记录了产生ANR的函数堆栈可以帮助分析
Android 通过logcat查看crash 或者anr日志