Android性能优化-ANR详解

2020-11-26 本文已影响0人沉淀者

简介：ANR问题是性能优化方面很重要的一个知识点，这里面主要考察的大家平时项目开发过程中的实践总结能力，这类问题不仅在开发中很容易遇到，在面试中也是很容易问到的，因此我在这里给大家提供一个思路去分析问题，面试官是很喜欢问的，年轻人，你有没有过ANR的经历，你是怎么分析总结的？年轻人，耗子尾汁，听到这我赶快学习总结归纳了一番！

一、ANR(Application Not Responding)定义

在Android上，如果你的应用程序有一段时间响应不够灵敏，系统会向用户显示一个对话框，这个对话框称作应用程序无响应（ANR：Application Not Responding）对话框。用户可以选择“等待”而让程序继续运行，也可以选择“强制关闭”。所以一个流畅的合理的应用程序中不能出现anr，而让用户每次都要处理这个对话框。因此，在程序里对响应性能的设计很重要，这样系统不会显示ANR给用户。

二、出现ANR的原因

默认情况下，在android中Activity的最长执行时间是5秒，BroadcastReceiver的最长执行时间则是10秒。超出就会提示应用程序无响应（ANR：Application Not Responding）对话框。

三、三种常见ANR类型

    1：KeyDispatchTimeout(5 seconds) --主要类型
　　按键或触摸事件在特定时间（5秒）内无响应
　　2：BroadcastTimeout(10 seconds)
　　BroadcastReceiver在特定时间（10秒）内无法处理完成
　　3：ServiceTimeout(20 seconds) --小概率类型
　　Service在特定的时间（20秒）内无法处理完成

四、分析ANR

1.产生ANR

很简单，就是一个按钮，然后点击它里面sleep,这样就会引发ANR异常

public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);

        findViewById(R.id.btn).setOnClickListener(new View.OnClickListener() {
            @Override
            public void onClick(View view) {
                try {
                    Thread.sleep(1000000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        });

    }
}

2.分析Android Studio的Logcat日志信息

//发生ANR的进程
E/ActivityManager( 127):ANR in cjh.com.androidaar (cjh.com.androidaar/.MainActivity)

//Reason表示导致ANR问题的直接原因
E/ActivityManager( 127): 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. waitqueue length = 2, head.seq = 871084, Wait queue head age: 57463.8ms.)
E/ActivityManager( 127): Load: 3.85 / 3.41 / 3.16

//请注意ago，表示ANR发生之前的一段时间内的CPU使用率，并不是某一时刻的值

E/ActivityManager( 127): CPU usage from 26835ms to 3662ms ago with 99% awake:

E/ActivityManager( 127): 9.4% 98/mediaserver: 9.4% user + 0% kernel

E/ActivityManager( 127): 8.9% 127/system_server: 6.9% user + 2% kernel / faults: 1823 minor

... ...

E/ActivityManager( 127): +0% 5033/com.example.anrdemo: 0% user + 0% kernel

E/ActivityManager( 127): 39% TOTAL: 32% user + 6.1% kernel

 

//这里是later，表示ANR发生之后

E/ActivityManager( 127): CPU usage from 601ms to 1132ms later with 99% awake:

E/ActivityManager( 127): 10% 127/system_server: 1.7% user + 8.9% kernel / faults: 5 minor

E/ActivityManager( 127): 10% 163/InputDispatcher: 1.7% user + 8.9% kernel

E/ActivityManager( 127): 1.7% 127/system_server: 1.7% user + 0% kernel

E/ActivityManager( 127): 1.7% 135/SurfaceFlinger: 0% user + 1.7% kernel

E/ActivityManager( 127): 1.7% 2814/Binder Thread #: 1.7% user + 0% kernel

... ...

E/ActivityManager( 127): 37% TOTAL: 27% user + 9.2% kernel

3.拉取traces.txt文件

当应用出现ANR的时候，在com\android\server\am\ActivityManagerService的appNotResponding方法被调用，然后ANR信息会被写到/data/anr/traces.txt文件中

接下来就将这个文件导出来，将手机连上电脑，然后打开dos窗口，如果没有配置环境变量，就直接定位到adb.exe目录去，然后输入如下命令

    > adb shell
    $ cd data/anr
    $ ls
    $ //这里就可以查看anr文件名称，并不是所有的手机厂商的文件名都是traces.txt
    anr_2020-11-26-09-52-09-684 dumptrace_BpkS7F
    $ exit
    //把tract.txt拉到电脑当前工作目录下面,如果是配置了adb环境，那就是默认在你的用户目录下面
    > adb pull data/anr/anr_2020-11-26-09-52-09-684 dumptrace_BpkS7F

这就将traces.txt文件拷贝到电脑d盘的ANR文件夹了，但是在一些高版本的手机上，会提示没有权限

adb: error: failed to copy 'data/anr/anr_2019-01-30-13-35-18-005' to '.\anr_2019-01-30-13-35-18-005': remote open failed: Permission denied

说明你这时候就不能用上述方式导出traces.txt文件了，因此你只能用下面这种方式导出系统运行log进行分析，这种方式也能得到anr信息，只不过它还包含其他很多信息，比如crash等的所有log都可以查看。

//6.0及以下设备
adb bugreport > bugreport.txt
//7.0及以上设备
adb bugreport bugreport.zip

然后你就能在当前工程下面看到导出的bugreport.zip压缩包了

image.png

4.查看bugreport压缩包

解压出来的文件如下

image.png

bugreport-<BUILD_ID>-<DATE>.txt: 最重要的文件，输出的诊断信息，包含：系统服务(dumpsys)，错误日志(dumpstate)，和系统日志信息(logcat)
version.txt: Android 的发布号
systrace.txt: 如果系统systrace是可用的，则会包含这个文件
FS 文件夹：dumpstate工具会将设备文件系统下的文件拷贝到FS文件夹下

然后在下面目录就能查看anr文件了

image.png

说明：
根据上面的内容可知，bugreport的生成非常简单，目录结构也很好理解，但问题是，这个生成的文件非常庞大，包含的信息量也很大，关于具体解析bug report的文件见官网，可以感受到其中的痛苦，因此Google针对Android5.0(API21)以上的系统开发了一个分析工具Battery Historian来解析bugreport文件，并用web图形的形式展示出来。具体使用可以参考这个网站：https://www.jianshu.com/p/a704e2268fe6

5.分析traces.txt文件

----- pid 26347 at 2020-11-26 09:52:09 -----
Cmd line: cjh.com.androidaar   //anr发生的进程名
Build fingerprint: 'HONOR/HRY-AL00a/HWHRY-HF:10/HONORHRY-AL00a/10.0.0.168C00:user/release-keys'
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=12069 post zygote classes=408
Dumping registered class loaders
....................
"main" prio=5 tid=1 Sleeping   //main是线程名 prio是线程优先级，默认是5 tid是线程锁id Sleeping   是线程状态的一种
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x73c97db0 self=0x711f410800  //group是线程组名称 sCount是线程被挂起次数 dsCount是线程被调试器挂起的次数 obj表示这个线程的java对象的地址 self表示这个线程本身的地址
  | sysTid=26347 nice=-10 cgrp=default sched=0/0 handle=0x71a60c3ed0  // sysTid是Linux下的内核线程id，nice是线程调度优先级 sched分别标志了线程的调度策略和优先级，cgrp是调度属组，handle是线程的处理函数地址 
  | state=S schedstat=( 697228125 37697920 363 ) utm=58 stm=11 core=5 HZ=100  // state是调度状态；schedstat三个值分别表示线程在cpu上执行的时间、线程的等待时间和线程执行的时间片长度；utm是线程用户态下使用的时间值(单位是jiffies）;stm是内核态下的调度时间值；core是最后执行这个线程的cpu核的序号
  | stack=0x7fc1650000-0x7fc1652000 stackSize=8192KB
  | held mutexes=
  at java.lang.Thread.sleep(Native method)
  - sleeping on <0x0f09ed2f> (a java.lang.Object)
  at java.lang.Thread.sleep(Thread.java:443)
  - locked <0x0f09ed2f> (a java.lang.Object)
  at java.lang.Thread.sleep(Thread.java:359)
  at cjh.com.androidaar.MainActivity$1.onClick(MainActivity.java:18)
  at android.view.View.performClick(View.java:7192)
  at android.view.View.performClickInternal(View.java:7166)
  at android.view.View.access$3500(View.java:824)
  at android.view.View$PerformClick.run(View.java:27592)
  at android.os.Handler.handleCallback(Handler.java:888)
  at android.os.Handler.dispatchMessage(Handler.java:100)
  at android.os.Looper.loop(Looper.java:213)
  at android.app.ActivityThread.main(ActivityThread.java:8178)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1101)

main prio=5 tid=1 Sleeping说明了线程名称、线程的优先级、线程锁id和线程状态。线程名称是启动线程的时候手动指明的，这里的main标识是主线程，是Android自动设定的一个线程名称，如果是自己手动创建的线程，一般会被命名成“Thread-xx”的格式，其中xx是线程id，它只增不减不会被复用；注意这其中的tid不是线程的id,它是一个在Java虚拟机中用来实现线程锁的变量，随着线程的增减，这个变量的值是可能被复用的；最后线程的状态还分为如下几种

image.png

Thread.java中的状态和Thread.cpp中的状态是有对应关系的。可以看到前者更加概括，也比较容易理解，面向Java的使用者；而后者更详细，面向虚拟机内部的环境。traces.txt中显示的线程状态都是Thread.cpp中定义的
特别说明一下MONITOR状态和SUSPEND状态，MONITOR状态一般是类的同步块或者同步方法造成的，SUSPENDED状态在debugger的时候会出现，可以用来区别是不是真的是用户正常操作跑出了ANR。

通过分析traces.txt文件可以获取到ANR的一些信息，比如ANR是哪个进程发生的，具体的调用信息；如果进程名是APP的进程名，那么main线程里会很清楚的写出是你的APP里哪块代码发生了ANR，就很容易去排查。像这里已经指出原因和位置：

  at java.lang.Thread.sleep(Thread.java:359)
  at cjh.com.androidaar.MainActivity$1.onClick(MainActivity.java:18)

这是一种比较简单的情况，实际开发中会遇到很多诡异的、更加复杂的情况.比如还需要去查看CPU使用率去查看IO占比那些，后面列举了几种常见的ANR在traces.txt文件中容易出现的类型。

6、其它ANR实例分析

在UI线程进行网络数据的读写

DALVIKTHREADS:
""main"" prio=5 tid=3 NATIVE
|group=""main"" sCount=1 dsCount=0 s=Yobj=0x4001b240 self=0xbda8
| sysTid=2579 nice=0 sched=0/0cgrp=unknown handle=-1343993184
atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStreamImpl(NativeMethod)
atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStream(OSNetworkSystem.java:478)
atorg.apache.harmony.luni.net.PlainSocketImpl.read(PlainSocketImpl.java:565)
atorg.apache.harmony.luni.net.SocketInputStream.read(SocketInputStream.java:87)
atorg.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnection$LimitedInputStream.read(HttpURLConnection.java:303)
atjava.io.InputStream.read(InputStream.java:133)
atjava.io.BufferedInputStream.fillbuf(BufferedInputStream.java:157)
atjava.io.BufferedInputStream.read(BufferedInputStream.java:346)
atandroid.graphics.BitmapFactory.nativeDecodeStream(Native Method)
atandroid.graphics.BitmapFactory.decodeStream(BitmapFactory.java:459)
atcom.android.mediascape.activity.PhotoViewerActivity.getPreviewImage(PhotoViewerActivity.java:4465)
atcom.android.mediascape.activity.PhotoViewerActivity.dispPreview(PhotoViewerActivity.java:4406)
atcom.android.mediascape.activity.PhotoViewerActivity.access$6500(PhotoViewerActivity.java:125)
atcom.android.mediascape.activity.PhotoViewerActivity$33$1.run(PhotoViewerActivity.java:4558)
atandroid.os.Handler.handleCallback(Handler.java:587)
atandroid.os.Handler.dispatchMessage(Handler.java:92)
atandroid.os.Looper.loop(Looper.java:123)
atandroid.app.ActivityThread.main(ActivityThread.java:4370)
atjava.lang.reflect.Method.invokeNative(Native Method)
atjava.lang.reflect.Method.invoke(Method.java:521)
atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)
atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)
atdalvik.system.NativeStart.main(Native Method)

数据库阻塞

DALVIK THREADS:
(mutexes: tll=0 tsl=0tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1 WAIT
|group="main" sCount=1 dsCount=0 obj=0x2aaca180self=0xcf20
| sysTid=1134 nice=0 sched=0/0 cgrp=[fopen-error:2]handle=1876218976
at java.lang.Object.wait(Native Method)
-waiting on <0x2aaca218> (a java.lang.VMThread)
atjava.lang.Thread.parkFor(Thread.java:1424)
atjava.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
atsun.misc.Unsafe.park(Unsafe.java:337)
atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:808)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:841)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1171)
atjava.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)
atjava.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
atandroid.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:378)
atandroid.database.sqlite.SQLiteCursor.<init>(SQLiteCursor.java:222)
atandroid.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:53)
atandroid.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1356)
atandroid.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1235)
atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1189)
atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1271)
atcom.android.email.provider.EmailProvider.query(EmailProvider.java:1098)
atandroid.content.ContentProvider$Transport.query(ContentProvider.java:187)
atandroid.content.ContentResolver.query(ContentResolver.java:268)
atcom.android.email.provider.EmailContent$Message.restoreMessageWithId(EmailContent.java:648)
atcom.android.email.Controller.setMessageRead(Controller.java:658)
atcom.android.email.activity.MessageView.onMarkAsRead(MessageView.java:700)
atcom.android.email.activity.MessageView.access$2500(MessageView.java:98)
atcom.android.email.activity.MessageView$LoadBodyTask.onPostExecute(MessageView.java:1290)
atcom.android.email.activity.MessageView$LoadBodyTask.onPostExecute(MessageView.java:1255)
atandroid.os.AsyncTask.finish(AsyncTask.java:417)
atandroid.os.AsyncTask.access$300(AsyncTask.java:127)
atandroid.os.AsyncTask$InternalHandler.handleMessage(AsyncTask.java:429)
atandroid.os.Handler.dispatchMessage(Handler.java:99)
atandroid.os.Looper.loop(Looper.java:123)
atandroid.app.ActivityThread.main(ActivityThread.java:3652)
atjava.lang.reflect.Method.invokeNative(Native Method)
atjava.lang.reflect.Method.invoke(Method.java:507)
atcom.android.internal.os.ZygoteIn

死锁

----- pid 9436 at 2015-11-28 21:30:41 -----
Cmd line: com.example.yxz.myapplication

JNI: CheckJNI is off; workarounds are off; pins=0; globals=277

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x415a4e88 self=0x414c48d8
  | sysTid=9436 nice=0 sched=0/0 cgrp=apps handle=1073926484
  | state=S schedstat=( 671264662 337280259 1005 ) utm=53 stm=14 core=0
  at com.example.yxz.myapplication.performancetest.WaitANR$InnerMonitorClass.TimeConsumeFunc(WaitANR.java:~48)
  - waiting to lock <0x447a5670>  held by tid=11 (Thread-14208)
  at com.example.yxz.myapplication.performancetest.WaitANR$2.run(WaitANR.java:32)
  at android.os.Handler.handleCallback(Handler.java:733)
  at android.os.Handler.dispatchMessage(Handler.java:95)
  at android.os.Looper.loop(Looper.java:212)
  at android.app.ActivityThread.main(ActivityThread.java:5135)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:515)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:878)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:694)
  at dalvik.system.NativeStart.main(Native Method)

....

"Thread-14208" prio=10 tid=11 TIMED_WAIT
  | group="main" sCount=1 dsCount=0 obj=0x447a4b98 self=0x78296bb8
  | sysTid=9955 nice=-8 sched=0/0 cgrp=apps handle=2015978016
  | state=S schedstat=( 946045 640869 1 ) utm=0 stm=0 core=2
  at java.lang.VMThread.sleep(Native Method)
  at java.lang.Thread.sleep(Thread.java:1013)
  at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:331)
  at com.example.yxz.myapplication.performancetest.WaitANR$InnerMonitorClass.TimeConsumeFunc(WaitANR.java:48)
  at com.example.yxz.myapplication.performancetest.WaitANR$1.run(WaitANR.java:20)
  at java.lang.Thread.run(Thread.java:841)

从trace文件可以看出，发生ANR的主线程正处于monitor状态，也就是它在等待一个synchronized块或者方法，但是目前这个monitor正在被tid=11的线程持有，所以造成了主线程被阻塞，从而发生了ANR。死锁的分析也是类似，发生死锁的线程一般处于MONITOR状态或者WAIT状态，等待其他进程的锁或者monitor，而其他进程又在等待另外线程的锁或者monitor，一直这样依赖下去，直到形成一个环。

五、总结

1: 首先分析Android Stduio自带的Logcat去查看ANR信息，里面一般会提供一些比较明显的信息
2: 在Logcat还是无法看出的话就需要查看trace.txt文件
3: 简单的错误trace.txt文件中直接比较明显的提供了发生错误的位置，无法明显得出信息的话就得结合线程状态等信息查看对应线程状态会发生的一些常见问题，仔细查看ANR的成因（iowait?block?memoryleak?），注意死锁和等待。还是无法得出问题的话就得继续下一步
5.查看CPU使用率，查看系统中运行的各进程CPU耗时占比，找出目标进程的cpu耗时占比，确认是user占比高，还是kernel占比高，还是iowait占比高；通过CPU使用率分析是不是IO等问题，这类问题相对比较复杂，需要自己加以摸索。

ANR是性能优化中一个很重要的点，有时候我们知道不能在线程中做一些耗时的操作，但在开发过程中还是会不知不觉引发ANR，此时就需要我们去分析哪里发生了问题，这类问题也比较看重实战训练，是比较重视经验方面的积累的，这里只是给大家一个思路，具体每个细节也有待考量，需要大家斟酌和去实践，谢谢大家的支持！！！

参考文章：（感谢）
1.https://blog.csdn.net/yxz329130952/article/details/50087731
2.https://blog.csdn.net/orangejuice11/article/details/72432007

Android性能优化-ANR详解

一、ANR(Application Not Responding)定义

二、出现ANR的原因

三、三种常见ANR类型

四、分析ANR

1.产生ANR

2.分析Android Studio的Logcat日志信息

3.拉取traces.txt文件

4.查看bugreport压缩包

5.分析traces.txt文件

6、其它ANR实例分析

五、总结

猜你喜欢

热点阅读