Android 性能优化(五)ANR 秒变大神

版权声明:本文为博主原创文章,未经博主允许不得转载。 https://blog.csdn.net/WHB20081815/article/details/70245594

一、概述

ANR(Application Not responding),是指应用程序未响应,Android系统对于一些事件需要在一定的时间范围内完成,如果超过预定时间能未能得到有效响应或者响应时间过长,都会造成ANR。

二:那么哪些场景会造成ANR呢?

     inputDispatching Timeout: 输入事件分发超时5s,包括按键分发事件的超时。==主要类型

     BroadcastQueue Timeout:比如前台广播在10s内执行完成

     ContentProvider Timeout:内容提供者执行超时(读写权限导致的)

  • Service Timeout:服务在20s内未执行完成;===小概率类型

三:如何避免KeyDispatchTimeout

1UI线程尽量只做跟UI相关的工作

2:耗时的工作(比如数据库操作,I/O,连接网络或者别的有可能阻碍UI线程的操作)把它放入单独的线程处理

3:尽量用Handler来处理UIthread和别的thread之间的交互

4.使用AsyncTask处理耗时IO操作。

5使用Thread或者HandlerThread时,调用Process.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND)设置优先级,否则仍然会降低程序响应,因为默认Thread的优先级和主线程相同。

6.使用Handler处理工作线程结果,而不是使用Thread.wait()或者Thread.sleep()来阻塞主线程

7.Activity的onCreate和onResume回调中尽量避免耗时的代码

8.BroadcastReceiver中onReceive代码也要尽量减少耗时,建议使用IntentService处理。


四:如何去分析ANR


主要发送ANR, 则会输出

  • 各个进程的CPU使用情况;
  • CPU负载;
  • IOWait;
  • traces文件
发生ANR时Android为我们提供了两种“利器”:traces文件和CPU使用率。

 对于从事Android开发的人来说,遇到ANR(Application Not Responding)是比较常见的问题。一般情况下,果ANR发生,对应的应用会收到SIGQUIT异常终止信号,dalvik虚拟机就会自动在/data/anr/目录下生成trace.txt文件,这个文件记录了在发生ANR时刻系统各个线程的执行状态,获取这个文件是不需要root权限的,因此首先需要做的就是通过adb pull命令将这个文件导出并等待分析。。产生ANR的原因有很多,比如CPU使用过高、事件没有得到及时的响应、死锁等,

案例一:

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40025340 self=0xd180
  | sysTid=1071 nice=0 sched=0/0 cgrp=default handle=-1344994080
  | schedstat=( 2355584448 1199910712 3410 )
  at java.net.InetAddress.getaddrinfo(Native Method)
  at java.net.InetAddress.lookupHostByName(InetAddress.java:540)
  at java.net.InetAddress.getAllByNameImpl(InetAddress.java:333)
  at java.net.InetAddress.getAllByName(InetAddress.java:295)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:100)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:79)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection$Address.connect(HttpConnection.java:353)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnectionPool.get(HttpConnectionPool.java:120)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getHttpConnection(HttpURLConnectionImpl.java:316)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.makeConnection(HttpURLConnectionImpl.java:298)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.connect(HttpURLConnectionImpl.java:236)
  at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getOutputStream(HttpURLConnectionImpl.java:645)
  at com.rayray.cool.util.URLUtil.invokeURL(URLUtil.java:136)
  at com.rayray.cool.activity.WoDeJianYiActivity$1.onClick(WoDeJianYiActivity.java:173)
  at android.view.View.performClick(View.java:2535)
  at android.view.View$PerformClick.run(View.java:9129)
  at android.os.Handler.handleCallback(Handler.java:618)
  at android.os.Handler.dispatchMessage(Handler.java:123)
  at android.os.Looper.loop(SourceFile:351)
  at android.app.ActivityThread.main(ActivityThread.java:3821)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:538)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:969)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:727)
  at dalvik.system.NativeStart.main(Native Method)


出现ANR问题的原因就是上面红色代码中
at com.rayray.cool.activity.WoDeJianYiActivity$1.onClick(WoDeJianYiActivity.java:173) 是Android中Activity
at com.rayray.cool.util.URLUtil.invokeURL(URLUtil.java:136) 是一次耗时的联网请求


Activity中的按键事件在特定事件内未响应造成。

案列二:IO写文件超时

先看个LOG:

04-01 13:12:11.572 I/InputDispatcher( 220): Application is not responding:Window{2b263310com.Android.email/com.android.email.activity.SplitScreenActivitypaused=false}.  5009.8ms since event, 5009.5ms since waitstarted

04-0113:12:11.572 I/WindowManager( 220): Input event dispatching timedout sending tocom.android.email/com.android.email.activity.SplitScreenActivity

04-01 13:12:14.123 I/Process(  220): Sending signal. PID: 21404 SIG: 3---发生ANR的时间和生成trace.txt的时间

04-01 13:12:14.123 I/dalvikvm(21404):threadid=4: reacting to signal 3 

……

04-0113:12:15.872 E/ActivityManager(  220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity)

04-0113:12:15.872 E/ActivityManager(  220): Reason:keyDispatchingTimedOut

04-0113:12:15.872 E/ActivityManager(  220): Load: 8.68 / 8.37 / 8.53

04-0113:12:15.872 E/ActivityManager(  220): CPUusage from 4361ms to 699ms ago ----CPUANR发生前的使用情况


04-0113:12:15.872 E/ActivityManager(  220):   5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults: 10 minor

04-0113:12:15.872 E/ActivityManager(  220):   4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11 minor 2 major

04-0113:12:15.872 E/ActivityManager(  220):   0.9%52/spi_qsd.0: 0% user + 0.9% kernel

04-0113:12:15.872 E/ActivityManager(  220):   0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel

04-0113:12:15.872 E/ActivityManager(  220):   0.5%296/com.android.systemui: 0.5% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(  220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait

04-0113:12:15.872 E/ActivityManager(  220): CPUusage from 3697ms to 4223ms later:-- ANRCPU的使用量======later是标志

04-0113:12:15.872 E/ActivityManager(  220):   25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor

04-0113:12:15.872 E/ActivityManager(  220):    16% 21603/__eas(par.hakan: 16% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(  220):    7.2% 21406/GC: 7.2% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(  220):    1.8% 21409/Compiler: 1.8% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(  220):   5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor

04-0113:12:15.872 E/ActivityManager(  220):    5.5% 263/InputDispatcher: 0% user + 5.5% kernel

04-0113:12:15.872 E/ActivityManager(  220): 32%TOTAL: 28% user + 3.7% kernel


LOG可以看出ANR的类型,CPU的使用情况,如果CPU使用量接近100%,说明当前设备很忙,有可能是CPU饥饿导致了ANR

如果CPU使用量很少,说明主线程被BLOCK

如果IOwait很高,说明ANR有可能是主线程在进行I/O操作造成的

除了看LOG,解决ANR还得需要trace.txt文件,


trace.txt文件,看到最多的是如下的信息:

-----pid 21404 at 2011-04-01 13:12:14 -----  
Cmdline: com.android.email

DALVIK THREADS:
(mutexes: tll=0tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1NATIVE
  | group="main" sCount=1 dsCount=0obj=0x2aad2248 self=0xcf70
  | sysTid=21404 nice=0 sched=0/0cgrp=[fopen-error:2] handle=1876218976
  atandroid.os.MessageQueue.nativePollOnce(Native Method)
  atandroid.os.MessageQueue.next(MessageQueue.java:119)
  atandroid.os.Looper.loop(Looper.java:110
)
 at android.app.ActivityThread.main(ActivityThread.java:3688)
 at java.lang.reflect.Method.invokeNative(Native Method)
  atjava.lang.reflect.Method.invoke(Method.java:507)
  atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
 at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:624)
 at dalvik.system.NativeStart.main(Native Method)

说明主线程在等待下条消息进入消息队列


案列三:死锁:

刚拿到anr的trace,还是无头绪,都是调用栈的dump,仔细看看,发现一个很好的信息隐藏在这个栈帧信息中:
如下一个栈帧:

----- pid 861 at 2012-02-11 14:57:50 -----
Cmd line: system_server
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x2ba9c460 self=0x8e820
  | sysTid=861 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=716342112
  | schedstat=( 0 0 0 ) utm=464 stm=65 core=0
  at com.android.server.am.ActivityManagerService.isUserAMonkey(ActivityManagerService.java:~6546)
  - waiting to lock <0x2c1141c8> (a com.android.server.am.ActivityManagerService) held by tid=59 (Binder Thread #6)
  at android.app.ActivityManagerNative.onTransact(ActivityManagerNative.java:1273)
  at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:1545)
  at android.os.Binder.execTransact(Binder.java:338)
  at com.android.server.SystemServer.init1(Native Method)
  at com.android.server.SystemServer.main(SystemServer.java:808)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
  at dalvik.system.NativeStart.main(Native Method)

这说明什么?看上面的红色部分,说明这个主线程在等待锁一个object 0x2c1141c8 (通常就是synchronized操作,这里就是com.android.server.am.ActivityManagerService类型的一个object),但被tid=59占住了, 再看看 tid=59的栈帧:

"Binder Thread #6" prio=5 tid=59 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x2c3bd838 self=0x34c5d8
  | sysTid=1120 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=3460688
  | schedstat=( 0 0 0 ) utm=168 stm=48 core=0
  at com.android.server.am.BatteryStatsService.noteStopWakelock(BatteryStatsService.java:~114)
  - waiting to lock <0x2c117d50> (a com.android.internal.os.BatteryStatsImpl) held by tid=13 (ProcessStats)
  at com.android.server.PowerManagerService.noteStopWakeLocked(PowerManagerService.java:798)
  at com.android.server.PowerManagerService.releaseWakeLockLocked(PowerManagerService.java:1015)
  at com.android.server.PowerManagerService.releaseWakeLock(PowerManagerService.java:967)
  at android.os.PowerManager$WakeLock.release(PowerManager.java:319)
  at android.os.PowerManager$WakeLock.release(PowerManager.java:300)
  at com.android.server.am.ActivityStack.activityIdleInternal(ActivityStack.java:3254)
  at com.android.server.am.ActivityManagerService.activityIdle(ActivityManagerService.java:3953)
  at android.app.ActivityManagerNative.onTransact(ActivityManagerNative.java:362)
  at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:1545)
  at android.os.Binder.execTransact(Binder.java:338)
  at dalvik.system.NativeStart.run(Native Method)

tid为何没有释放锁object 0x2c1141c8呢?因为它在等到锁 object 0x2c117d50(一个com.android.internal.os.BatteryStatsImpl类型的对象)!如果大家有较丰富的捉虫经验的话,看到这, 想必都清楚了,持锁时又请求锁,极大的可能就是死锁了!



案列四:
//显示进程id、ANR发生时间点、ANR发生进程包名----- pid 19073 at 2015-10-08 17:24:38 -----Cmd line: com.example.yanbo.myapplication//一些GC等object信息,通常可以忽略......//ANR方法堆栈打印信息!重点!DALVIK THREADS (18):"main" prio=5 tid=1 Sleeping | group="main" sCount=1 dsCount=0 obj=0x7497dfb8 self=0x7f9d09a000 | sysTid=19073 nice=0 cgrp=default sched=0/0 handle=0x7fa106c0a8 | state=S schedstat=( 125271779 68162762 280 ) utm=11 stm=1 core=0 HZ=100 | stack=0x7fe90d3000-0x7fe90d5000 stackSize=8MB | held mutexes= at java.lang.Thread.sleep!(Native method) - sleeping on <0x0a2ae345> (a java.lang.Object) at java.lang.Thread.sleep(Thread.java:1031) - locked <0x0a2ae345> (a java.lang.Object)//真正导致ANR的问题点,可以发现是onClick中有sleep导致。我们平时可以类比分析即可,这里不详细说明。 at java.lang.Thread.sleep(Thread.java:985) at com.example.yanbo.myapplication.MainActivity$1.onClick(MainActivity.java:21) at android.view.View.performClick(View.java:4908) at android.view.View$PerformClick.run(View.java:20389) at android.os.Handler.handleCallback(Handler.java:815) at android.os.Handler.dispatchMessage(Handler.java:104) at android.os.Looper.loop(Looper.java:194) at android.app.ActivityThread.main(ActivityThread.java:5743) 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:988) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:783)......//省略一些不常关注堆栈打印


ANR强势分析工具:
  • 使用Systrace和TraceView找出影响响应的问题。
最后:正确使用Android性能分析工具——TraceView


一、TraceView简介

      TraceView是AndroidSDK里面自带的工具,用于对Android的应用程序以及Framework层的代码进行性能分析。

      TraceView是图形化的工具,最终它会产生一个图表,用于对性能分析进行说明。

      TraceView可以跟踪到具体的Method



一个方法后可以看到有两部分,一个是Parents,另一个是Children。

  • Parent表示调用这个方法的方法,可以叫做父方法
  • Children表示这个方法中调用的其他方法,可以叫做子方法

raceView罗列出了是所有监听到的方法,当然也包括Android系统很多方法的耗时,如何在这么多方法里面查找到自己关心的? 可以通过TraceView 底部的find 来查找,通常Android app都是有包名的,可以先针对某些关心的列排序后,在通过包名进行一个个查找,这些就省去自己筛选出自己app 方法耗时排行的时间。
使用方法:




参考博客:

http://www.jianshu.com/p/ba630177d85a


阅读更多
想对作者说点什么?

博主推荐

换一批

没有更多推荐了,返回首页