Android ANR详解(下)

jianning-wu

已于 2023-08-08 10:25:50 修改

阅读量1.5k

点赞数

分类专栏： Android 进阶文章标签： Android ANR nativePollOnce Android 卡顿 MessageQueue ANR监控 I am_meminfo

于 2017-04-21 15:22:41 首次发布

本文链接：https://blog.csdn.net/weixin_37730482/article/details/70317767

版权

Android 进阶专栏收录该内容

20 篇文章 6 订阅

订阅专栏

本章节继续讲解ANR的相关问题

一.ANR原因分析

1.系统导致ANR

<1> CPU被抢占：比如，前台在操作游戏的app，可能会导致你的APP后台广播被抢占CPU，导致广播中相关代码执行超时导致ANR。

<2> 系统服务无法及时响应：比如你的APP要获取系统联系人，系统的服务都是Binder机制，服务能力也是有限的，有可能系统服务长时间不响应导致ANR。

<3> 其他应用占用的大量内存。其他应用占用大量内容，导致手机变慢变卡，从而可能导致你的APP出现ANR。

2.应用层导致ANR

<1> 函数阻塞：如死循环、主线程IO、处理大数据。(主线程有耗时操作)

<2> 锁出错：主线程等待子线程的锁。

<3> 内存紧张：系统分配给一个应用的内存是有上限的，长期处于内存紧张，会导致频繁内存交换，进而导致应用的一些操作超时。

二.名词解释

Load: 5.14 / 5.28 / 5.33

表示：第1、5、15 分钟内正在使用和等待使用CPU 的活动进程的平均数。

CPU usage from 0ms to 15505ms later (2017-04-21 09:34:34.924 to 2017-04-021 09:34:50.429):
      10% 1738/system_server: 4.6% user + 5.4% kernel / faults: 2267 minor
      4.7% 9154/com.android.browser: 1.8% user + 2.9% kernel / faults: 2070 minor 21 major
      3.6% 453/logd: 3.2% user + 0.3% kernel / faults: 10 minor
      0% 911/media.codec: 0% user + 0% kernel / faults: 4350 minor
      2.3% 309/irq/72-ft5435_t: 0% user + 2.3% kernel
      2.1% 2120/com.android.systemui: 1.4% user + 0.7% kernel / faults: 1702 minor 73 major
      2.1% 429/ueventd: 1.5% user + 0.5% kernel
      1% 2495/com.android.phone: 0.7% user + 0.3% kernel / faults: 232 minor
      0.9% 15060/kworker/u16:5: 0% user + 0.9% kernel
      0.8% 11544/adbd: 0% user + 0.8% kernel / faults: 201 minor
      0.7% 579/healthd: 0% user + 0.7% kernel
      0.7% 566/android.hardware.sensors@1.0-service: 0.5% user + 0.1% kernel / faults: 105 minor
      0.7% 9875/com.sohu.inputmethod.sogou.xiaomi: 0.6% user + 0% kernel / faults: 305 minor
      0.6% 11316/com.example.myapplication: 0.5% user + 0.1% kernel / faults: 1144 minor
    

      .............省略N行........................................................      

      0% 827/c

第一行表示：表明trace信息抓取在ANR发生之后的0~1987ms。同时也指明了ANR的时间点2017-04-21 09:34:34.924 to 2017-04-021 09:34:50.429。

第二行表示：各个进程占用的CPU的详细情况。自己app测试ANR的占用cpu%0.6

11316/com.example.myapplication

<1> user:表示用户态
 
<2> kernel:表示内核态

<3> faults:表示内存缺页。minor——轻微的&major——重度

<4> iowait:IO使用/等待占比

<5> irq:硬中断，softirq:软中断


注意：
<1> iowait占比很高，意味着有很大可能，是io耗时导致ANR，具体进一步查看有没有进程faults major比较多。

<2> 单进程CPU的负载并不是以100%为上限，而是有几个核，就有百分之几百，如2核上限为200%。

"main" prio=5 tid=1 Native

"ReferenceQueueDaemon" daemon prio=5 tid=10 Waiting


发生ANR的进程包含的所有线程的状态

main：主线程

ReferenceQueueDaemon：其他线程

Java中线程有几种状态 详见https://blog.csdn.net/weixin_37730482/article/details/70331807

ANR中线程的状态和Java中线程的状态对比图

ANR线程状态

Java线程状态

说明

Zombie

Terminated

线程死亡，终止运行

Running/Runnable

Runnable

线程可运行或正在运行

Timed_Wait

Timed_WaitIng

执行了带有超时参数的wait&sleep&join函数

Wait

WaitIng

执行了无超时参数的wait函数

Monitor

Blocked

线程堵塞，等待获取对象锁

Initializing

New

新建，正在初始化

StartIng

New

新建，正在启动

Native

Runnable

正在执行JNI本地函数

Vmwait

WaitIng

正在等待VM资源

Suspended

Runnable

线程暂停，一般是由于GC或Debug被暂停

备注：main线程处于 BLOCK、WAITING、TIMEWAITING状态，那基本上是函数阻塞导致ANR。

、

三.案例分析

1.案例1 系统服务超时导致ANR

系统服务超时导致的ANR，trace日志中一般会包含BinderProxy.transactNative关键字。

"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x727851e8 self=0x78d7060e00
  | sysTid=5694 nice=0 cgrp=default sched=0/0 handle=0x795cc1e9a8
  | state=S schedstat=( 8292806752 1621087524 7167 ) utm=707 stm=122 core=5 HZ=100
  | stack=0x7febb64000-0x7febb66000 stackSize=8MB
  | held mutexes=
  kernel: __switch_to+0x90/0xc4
  kernel: binder_thread_read+0xbd8/0x144c
  kernel: binder_ioctl_write_read.constprop.58+0x20c/0x348
  kernel: binder_ioctl+0x5d4/0x88c
  kernel: do_vfs_ioctl+0xb8/0xb1c
  kernel: SyS_ioctl+0x84/0x98
  kernel: cpu_switch_to+0x34c/0x22c0
  native: #00 pc 000000000007a2ac  /system/lib64/libc.so (__ioctl+4)
  native: #01 pc 00000000000276ec  /system/lib64/libc.so (ioctl+132)
  native: #02 pc 00000000000557d4  /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+252)
  native: #03 pc 0000000000056494  /system/lib64/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*, int*)+60)
  native: #04 pc 00000000000562d0  /system/lib64/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+216)
  native: #05 pc 000000000004ce1c  /system/lib64/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+72)
  native: #06 pc 00000000001281c8  /system/lib64/libandroid_runtime.so (???)
  native: #07 pc 0000000000947ed4  /system/framework/arm64/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+196)
  at android.os.BinderProxy.transactNative(Native method) 
  at android.os.BinderProxy.transact(Binder.java:804)
  at android.net.IConnectivityManager$Stub$Proxy.getActiveNetworkInfo(IConnectivityManager.java:1204)
  at android.net.ConnectivityManager.getActiveNetworkInfo(ConnectivityManager.java:800)
  at com.xiaomi.NetworkUtils.getNetworkInfo(NetworkUtils.java:2)
  at com.xiaomi.frameworkbase.utils.NetworkUtils.getNetWorkType(NetworkUtils.java:1)
  at com.xiaomi.frameworkbase.utils.NetworkUtils.isWifiConnected(NetworkUtils.java:1)

2.案例2 内存紧张导致ANR

内存紧张导致的ANR,trace日志中一般会包含 onTrimMemory关键字。

04-21 15:22:41.479 20733 20733 E Runtime : onTrimMemory level:80......

3.案例3 CPU被抢占导致ANR

 CPU usage from 0ms to 15505ms later (2017-04-21 09:34:34.924 to 2017-04-21 09:34:50.429):
      510% 1738/com.XXX.XXX.XXX 46% user + 54% kernel / faults: 4267 minor
      97% 9154/com.android.browser: 1.8% user + 2.9% kernel / faults: 2070 minor 21 major
      36% 453/logd: 3.2% user + 0.3% kernel / faults: 10 minor
      ......省略N行......

如上trace日志，com.XXX.XXX.XXX进程，占据CPU高达510%，抢占了大部分CPU资源，因而导致发生ANR。

4.案例4 主线程被锁阻塞导致ANR

如上trace日志，主线程被锁堵塞导致的ANR，一般会有如下几个特点。

<1> 主线程main处于 Blocked&Waiting&Sleeping状态。

<2> trace日志中有lock&locked关键字。

主线程被堵塞导致ANR常见的场景是SharePreference写入操作。

详情：SharedPreferences详解_jianning-wu的博客-CSDN博客

5.案例5 输入超时导致ANR

2017-04-21 09:29:34.124 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:29:34.124 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:29:45.992 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:29:45.993 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:30:04.126 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:30:04.127 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:30:15.995 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:30:15.995 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:30:34.129 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:30:34.129 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:30:37.041 569-569/? E/WifiHAL: wifi_get_logger_supported_feature_set: Error -3 happened. 
2017-04-21 09:30:37.050 1738-2029/system_process E/WifiVendorHal: getSupportedFeatureSet(l.975) failed {.code = ERROR_NOT_SUPPORTED, .description = }
2017-04-21 09:30:37.053 569-569/? E/WifiHAL: wifi_get_logger_supported_feature_set: Error -3 happened. 
2017-04-21 09:30:37.064 1738-1800/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for wifi
2017-04-21 09:30:37.112 569-569/? E/WifiHAL: wifi_get_logger_supported_feature_set: Error -3 happened. 
2017-04-21 09:30:37.113 1738-2029/system_process E/WifiVendorHal: getSupportedFeatureSet(l.975) failed {.code = ERROR_NOT_SUPPORTED, .description = }
2017-04-21 09:30:37.114 569-569/? E/WifiHAL: wifi_get_logger_supported_feature_set: Error -3 happened. 
2017-04-21 09:30:45.998 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:30:45.998 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:31:04.132 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:31:04.132 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:31:16.000 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:31:16.000 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:31:34.135 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:31:34.135 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:31:46.003 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:31:46.003 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:32:04.137 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:32:04.137 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:32:16.005 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:32:16.005 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:32:34.140 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:32:34.140 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:32:46.008 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:32:46.008 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:33:04.142 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:33:04.142 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:33:16.010 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:33:16.010 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:33:34.145 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:33:34.145 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:33:44.888 1738-1894/system_process E/ActivityTrigger: activityStartTrigger: not whiteListedcom.miui.securitycenter/com.miui.permcenter.install.AdbInstallActivity/350
2017-04-21 09:33:44.890 1738-1894/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.miui.securitycenter/com.miui.permcenter.install.AdbInstallActivity/350
2017-04-21 09:33:44.895 1738-14561/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.miui.securitycenter/com.miui.permcenter.install.AdbInstallActivity/350
2017-04-21 09:33:44.899 575-610/? E/ANDR-PERF-UTIL: Failed to read 
2017-04-21 09:33:44.900 575-610/? E/ANDR-PERF-UTIL: Failed to read 
2017-04-21 09:33:44.900 575-610/? E/ANDR-PERF-OPTSHANDLER: Failed to read /sys/class/kgsl/kgsl-3d0/force_no_nap
2017-04-21 09:33:44.900 575-610/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [10, 7]
2017-04-21 09:33:44.980 1738-3548/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.miui.home/com.miui.home.launcher.Launcher/41521515
2017-04-21 09:33:44.981 575-610/? E/ANDR-PERF-OPTSHANDLER: Failed to read /sys/class/kgsl/kgsl-3d0/force_no_nap
2017-04-21 09:33:44.981 575-610/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [10, 7]
2017-04-21 09:33:45.254 2511-2511/com.miui.home E/Launcher: changeViewByFsGestureState,  view=FitSystemWindowView,  alpha=1.0,  scale=1.0
2017-04-21 09:33:45.254 2511-2511/com.miui.home E/Launcher: changeViewByFsGestureState,  view=ShortcutMenuLayer,  alpha=1.0,  scale=1.0
2017-04-21 09:33:45.382 575-610/? E/ANDR-PERF-OPTSHANDLER: perf_lock_rel: updated /sys/class/mmc_host/mmc0/clk_scaling/enable with 1
     return value 2
2017-04-21 09:33:46.011 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:33:46.011 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:33:47.395 835-1949/? E/installd: Failed to delete /data/app/vmdl2139688293.tmp: No such file or directory
2017-04-21 09:33:47.415 1738-3453/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.415 1738-3453/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.427 1738-3548/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.428 1738-3548/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.447 1738-3676/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.447 1738-3676/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.455 1738-3645/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.455 1738-3645/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.464 2495-2495/com.android.phone E/VvmPkgInstalledRcvr: cannot create TelephonyManager from ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, [****], UserHandle{0}
2017-04-21 09:33:47.474 1738-14561/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.474 1738-14561/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.497 1738-3645/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.497 1738-3645/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.541 1738-1738/system_process E/LockSettingsStorage:  HQ-30462 cache is [B@b6ab719
2017-04-21 09:33:47.541 1738-1738/system_process E/LockSettingsStorage: HQ-30643 Synthetic is not null -----------
2017-04-21 09:33:47.613 1738-3381/system_process E/ANDR-PERF-JNI: com_qualcomm_qtiperformance_native_perf_io_prefetch_start
2017-04-21 09:33:47.616 1738-3381/system_process E/ActivityTrigger: activityStartTrigger: not whiteListedcom.example.myapplication/com.example.myapplication.chart.MainActivity/1
2017-04-21 09:33:47.620 1738-3381/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.example.myapplication/com.example.myapplication.chart.MainActivity/1
2017-04-21 09:33:47.624 1738-14561/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.example.myapplication/com.example.myapplication.chart.MainActivity/1
2017-04-21 09:33:48.512 1738-1817/system_process E/ANDR-PERF-JNI: com_qualcomm_qtiperformance_native_perf_io_prefetch_start
2017-04-21 09:33:52.866 4522-4773/com.xiaomi.market E/Market-UpdateDesktopOperateIconManager: [OperateIconConfig] JSON : operation icon config list not exist!
2017-04-21 09:34:04.147 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:34:04.147 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:34:16.013 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:34:16.014 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:34:34.150 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:34:34.150 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:34:37.245 1738-1792/system_process E/zygote64: libdebuggerd_client: failed to send signal to pid 908: Permission denied
2017-04-21 09:34:40.566 455-455/? E/SELinux: avc:  denied  { find } for interface=android.hardware.memtrack::IMemtrack pid=9154 scontext=u:r:platform_app:s0:c512,c768 tcontext=u:object_r:hal_memtrack_hwservice:s0 tclass=hwservice_manager permissive=0
2017-04-21 09:34:40.567 455-455/? E/SELinux: avc:  denied  { find } for interface=android.hardware.memtrack::IMemtrack pid=9154 scontext=u:r:platform_app:s0:c512,c768 tcontext=u:object_r:hal_memtrack_hwservice:s0 tclass=hwservice_manager permissive=0
2017-04-21 09:34:40.570 455-455/? E/SELinux: avc:  denied  { find } for interface=android.hardware.memtrack::IMemtrack pid=9154 scontext=u:r:platform_app:s0:c512,c768 tcontext=u:object_r:hal_memtrack_hwservice:s0 tclass=hwservice_manager permissive=0
2017-04-21 09:34:46.016 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:34:46.016 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:34:49.366 1738-1792/system_process E/zygote64: libdebuggerd_client: failed to read response from tombstoned: timeout reached?
2017-04-21 09:34:50.481 1738-1792/system_process E/ActivityManager: ANR in com.example.myapplication (com.example.myapplication/.chart.MainActivity)
    PID: 11316
    Reason: Input dispatching timed out (com.example.myapplication/com.example.myapplication.chart.MainActivity, 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: 2.  Wait queue head age: 32718.2ms.)
    Load: 5.14 / 5.28 / 5.33
    CPU usage from 0ms to 15505ms later (2017-04-21 09:34:34.924 to 2017-04-21 09:34:50.429):
      10% 1738/system_server: 4.6% user + 5.4% kernel / faults: 2267 minor
      4.7% 9154/com.android.browser: 1.8% user + 2.9% kernel / faults: 2070 minor 21 major
      3.6% 453/logd: 3.2% user + 0.3% kernel / faults: 10 minor
      0% 911/media.codec: 0% user + 0% kernel / faults: 4350 minor
      2.3% 309/irq/72-ft5435_t: 0% user + 2.3% kernel
      2.1% 2120/com.android.systemui: 1.4% user + 0.7% kernel / faults: 1702 minor 73 major
      2.1% 429/ueventd: 1.5% user + 0.5% kernel
      1% 2495/com.android.phone: 0.7% user + 0.3% kernel / faults: 232 minor
      0.9% 15060/kworker/u16:5: 0% user + 0.9% kernel
      0.8% 11544/adbd: 0% user + 0.8% kernel / faults: 201 minor
      0.7% 579/healthd: 0% user + 0.7% kernel
      0.7% 566/android.hardware.sensors@1.0-service: 0.5% user + 0.1% kernel / faults: 105 minor
      0.7% 9875/com.sohu.inputmethod.sogou.xiaomi: 0.6% user + 0% kernel / faults: 305 minor
      0.6% 11316/com.example.myapplication: 0.5% user + 0.1% kernel / faults: 1144 minor
      0.5% 82/kworker/u16:1: 0% user + 0.5% kernel
      0.5% 593/surfaceflinger: 0.3% user + 0.1% kernel / faults: 191 minor
      0.4% 910/wificond: 0% user + 0.4% kernel
      0.4% 10063/kworker/u16:3: 0% user + 0.4% kernel
      0.4% 24572/VosMCThread: 0% user + 0.4% kernel
      0% 842/media.extractor: 0% user + 0% kernel / faults: 1631 minor
      0.3% 21872/kworker/7:0H: 0% user + 0.3% kernel
      0.3% 3744/com.tencent.mm: 0% user + 0.2% kernel / faults: 10 minor
      0.2% 352/cfinteractive: 0% user + 0.2% kernel
      0.2% 11162/kworker/u16:0: 0% user + 0.2% kernel
      0.2% 12048/kworker/6:0H: 0% user + 0.2% kernel
      0.1% 7/rcu_preempt: 0% user + 0.1% kernel
      0.1% 362/mmc-cmdqd/0: 0% user + 0.1% kernel
      0.1% 553/android.hardware.graphics.composer@2.1-service: 0% user + 0.1% kernel / faults: 130 minor
      0.1% 565/android.hardware.power@1.0-service: 0% user + 0.1% kernel
      0.1% 909/storaged: 0.1% user + 0% kernel
      0% 931/tombstoned: 0% user + 0% kernel
      0.1% 993/msm_irqbalance: 0% user + 0.1% kernel
      0% 1//init: 0% user + 0% kernel
      0.1% 3/ksoftirqd/0: 0% user + 0.1% kernel
      0.1% 10/rcuop/0: 0% user + 0.1% kernel
      0.1% 45/rcuop/4: 0% user + 0.1% kernel
      0.1% 554/android.hardware.health@1.0-service: 0% user + 0% kernel
      0.1% 2086/com.android.bluetooth: 0% user + 0.1% kernel / faults: 114 minor
      0.1% 2511/com.miui.home: 0% user + 0.1% kernel / faults: 6 minor
      0.1% 3661/com.miui.securitycenter.remote: 0% user + 0.1% kernel / faults: 8 minor
      0.1% 4522/com.xiaomi.market: 0% user + 0% kernel / faults: 3 minor
      0.1% 7817/com.tencent.mm:push: 0% user + 0% kernel / faults: 13 minor
      0.1% 10330/kworker/5:1: 0% user + 0.1% kernel
      0.1% 10974/logcat: 0% user + 0.1% kernel
      0.1% 11174/kworker/0:3: 0% user + 0.1% kernel
      0.1% 19613/com.tencent.mobileqq:MSF: 0% user + 0% kernel / faults: 25 minor 2 major
      0.1% 27724/kworker/5:2H: 0% user + 0.1% kernel
      0% 18/ksoftirqd/1: 0% user + 0% kernel
      0% 29/rcuop/2: 0% user + 0% kernel
      0% 37/rcuop/3: 0% user + 0% kernel
      0% 46/rcuos/4: 0% user + 0% kernel
      0% 53/rcuop/5: 0% user + 0% kernel
      0% 61/rcuop/6: 0% user + 0% kernel
      0% 69/rcuop/7: 0% user + 0% kernel
      0% 214/hwrng: 0% user + 0% kernel
      0% 266/kgsl_worker_thr: 0% user + 0% kernel
      0% 465/kauditd: 0% user + 0% kernel
      0% 469/vold: 0% user + 0% kernel
      0% 544/android.hardware.audio@2.0-service: 0% user + 0% kernel / faults: 41 minor
      0% 546/android.hardware.camera.provider@2.4-service: 0% user + 0% kernel / faults: 13 minor
      0% 568/android.hardware.vibrator@1.0-service: 0% user + 0% kernel
      0% 792/jbd2/dm-0-8: 0% user + 0% kernel
      0% 827/c
2017-04-21 09:34:52.326 1738-3676/system_process E/ActivityTrigger: activityResumeTrigger: not whiteListedcom.miui.home/com.miui.home.launcher.Launcher/41521515
2017-04-21 09:34:52.342 575-610/? E/ANDR-PERF-UTIL: Failed to read 
2017-04-21 09:34:52.342 575-610/? E/ANDR-PERF-UTIL: Failed to read 
2017-04-21 09:34:52.342 575-610/? E/ANDR-PERF-OPTSHANDLER: Failed to read /sys/class/kgsl/kgsl-3d0/force_no_nap
2017-04-21 09:34:52.342 575-610/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [10, 7]
2017-04-21 09:34:52.679 2511-2511/com.miui.home E/Launcher: changeViewByFsGestureState,  view=FitSystemWindowView,  alpha=1.0,  scale=1.0
2017-04-21 09:34:52.679 2511-2511/com.miui.home E/Launcher: changeViewByFsGestureState,  view=ShortcutMenuLayer,  alpha=1.0,  scale=1.0
2017-04-21 09:34:52.743 575-610/? E/ANDR-PERF-OPTSHANDLER: perf_lock_rel: updated /sys/class/mmc_host/mmc0/clk_scaling/enable with 1
     return value 2
2017-04-21 09:35:04.152 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:35:04.152 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed
2017-04-21 09:35:16.018 19613-19834/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 0 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:35:16.018 19613-19834/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 0socket hashCode: 0SocketReader(12580) errorjava.net.SocketException: Socket is closed
2017-04-21 09:35:34.155 19613-19835/com.tencent.mobileqq E/MSF.C.NetConnTag.true: conn is already closed on readError closeConn socketEngineID: 1 socket hashcode: 0java.lang.Throwable
        at com.tencent.mobileqq.msf.core.net.m.b(P:665)
        at com.tencent.mobileqq.msf.core.net.m$b.run(P:547)
2017-04-21 09:35:34.155 19613-19835/com.tencent.mobileqq E/SocketReaderNewtrue: socketEngine: 1socket hashCode: 0SocketReader(12581) errorjava.net.SocketException: Socket is closed

步骤1：全局搜索 ANR in

在trace文件找到app出问题的地方。

步骤2：在步骤1中下一行找到进程Id

全局搜索 11316

案例1是一个很简单的ANR。trace文件中直接给出了Reason。

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: 2.  Wait queue head age: 32718.2ms

很显然是输入事件响应超时，代码如下

......N行代码......

try {
    Thread.sleep(100000);
} catch (InterruptedException e) {
    e.printStackTrace();
}

......N行代码......

去掉线程sleep方法即可。

jianning-wu

关注

0
点赞
踩
5

收藏

觉得还不错? 一键收藏
0
评论
Android ANR详解(下)

其他应用占用的大量内存。系统服务无法及时响应。
复制链接

扫一扫

专栏目录

Android ANR详解(下)

本章节继续讲解ANR的相关问题

一.ANR原因分析

二.名词解释

三.案例分析

“相关推荐”对你有帮助么？