Input ANR的触发流程

最新推荐文章于 2024-07-30 14:53:26 发布

Aven_Coffee

最新推荐文章于 2024-07-30 14:53:26 发布

阅读量2.3k

点赞数

文章标签： ANR

本文链接：https://blog.csdn.net/chi_wy/article/details/84821810

版权

以MTK平台为例

1.CPU信息查看

当ANR发生时，会生成db文件；其中SYS_CPU_INFO会包含cpu的信息。

Tasks: 1976 total, 31 running,1928 sleeping, 0 stopped, 0 zombie
Mem: 2866928k total, 2826828k used, 40100k free, 6852k buffers
Swap: 1048572k total, 353344k used, 695228k free, 520232k cached
400%cpu 283%user 168%nice 102%sys 154%idle 2%iow 0%irq 0%sirq 0%host

参数说明：

user：CPU在用户态的运行时间，不包括nice值为负数的进程运行的时间
nice： CPU在用户态并且nice值为负数的进程运行的时间
sys：CPU在内核态运行的时间
idle：CPU空闲时间，不包括iowait时间
iow：CPU等待I/O操作的时间
irq：CPU硬中断的时间
sirq：CPU软中断的时间

相应的cpu的使用率，也可以通过如下命令实时抓取：# cat /proc/stat。

此外，在dump_cpuinfo文件中也可以看到某一时段内的cpu 平均负载信息。以下为某台XXXX上抓取的信息。

Load: 19.89 / 21.61 / 22.07
CPU usage from 67280ms to 14941ms ago (2018-09-01 14:49:32.291 to 2018-09-01 14:50:24.630):
85% 1161/com.android.systemui: 82% user + 3.2% kernel / faults: 29917 minor 22 major
31% 957/system_server: 27% user + 4.2% kernel / faults: 4969 minor 6 major

20% 25137/com.android.vending: 14% user + 6.4% kernel / faults: 17043 minor 3 major
10% 20267/android.process.media: 8.4% user + 1.7% kernel / faults: 7317 minor 29 major

..........

+0% 4864/kworker/3:2: 0% user + 0% kernel
55% TOTAL: 41% user + 11% kernel + 3.3% iowait + 0.3% softirq

Load:为cpu的平均负载，上面的3个值代表：在某一时刻的前一分钟、五分钟、十五分钟的CPU平均负载；

以上日志中的三个值分别是19.89 / 21.61 / 22.07，通常关注5/15分钟的平均负载，因为1分钟的平均负载太频繁，一瞬间的高并发就会导致该值的大幅度改变。

Linux 的系统负载指运行队列的平均长度，也就是等待 CPU 的平均进程数；相应的cpu的平均负载，也可以通过如下命令抓取:

XXXXX:/ $ cat /proc/loadavg
18.04 17.04 10.27 1/1831 8606

上述输出中每个值的含义依次为：

lavg_1 (18.04) 1-分钟平均负载
lavg_5 (17.04) 5-分钟平均负载
lavg_15(10.27) 15-分钟平均负载
nr_running (1) 在采样时刻，运行队列的任务的数目
nr_threads (1831) 在采样时刻，系统中活跃的任务的个数（不包括运行已经结束的任务）
last_pid(8606) 最大的pid值，包括轻量级进程，即线程。

2.内存信息查看

当ANR发生时，会生成db文件；其中DUMPSYS_MEMINFO 会包含 dump menfinfo的信息。

Total RAM: 2,866,932K (status normal)
Free RAM: 1,028,615K ( 755,567K cached pss + 229,448K cached kernel + 43,600K free)
Used RAM: 2,246,972K (1,923,460K used pss + 323,512K kernel)
Lost RAM: -37,629K
ZRAM: 272,520K physical used for 805,976K in swap (1,048,572K total swap)
Tuning: 256 (large 512), oom 322,560K, restore limit 107,520K (high-end-gfx)

其实MTK已经将总的、可用的内存打印出来了。可是很多人依然以 SYS_MEMORY_INFO中MemFree 很低为理由，归为低内存导致的anr，这其实是个误区；

如MTKZ抓取的Log打印，系统可用的内存空间是 = MemFree + Cached。

主要的几个参数的注释：

MemTotal: 2866932 kB   //所有可用RAM大小
MemFree: 19524 kB //系统留着未使用的内存
MemAvailable: 756212 kB 对应用来说可使用的内存，包含cache+buffer
Buffers: 24620 kB   //用来给文件做缓冲区的大小
Cached: 713632 kB   //被高速缓冲存储器(cache memory)用的内存的大小
SwapCached: 8876 kB //交换空间的大小已经被交换出来的内存
Active: 807600 kB //在活跃使用中的缓冲或高速缓冲存储器页面文件的大小
Inactive: 810108 kB   //在不经常使用中的缓冲或高速缓冲存储器页面文件的大小
Active(anon): 455744 kB
Inactive(anon): 457436 kB
Active(file): 351856 kB
Inactive(file): 352672 kB

Shmem: 1296 kB
Slab: 199004 kB //内核数据结构缓存的大小，可以减少申请和释放内存带来的消耗

SReclaimable: 62400 kB //可收回Slab的大小
SUnreclaim: 136604 kB //不可收回Slab的大小
KernelStack: 44672 kB

VmallocTotal: 263061440 kB //可以vmalloc虚拟内存大小

当然，如果你还想看看具体那个进程占的内存多；可以通过如下的命令查看：

C:\XXXXXXX>adb shell procrank

PID Vss Rss Pss Uss Swap PSwap USwap ZSwap cmdline

866 4660800K 310712K 140013K 94212K 288K 288K 288K 70K system_server

1816 4387828K 196264K 124524K 121964K 0K 0K 0K 0K com.transsion.faceid

1164 4495888K 235400K 105050K 89856K 0K 0K 0K 0K com.android.systemui

22479 1826744K 171424K 85793K 63544K 0K 0K 0K 0K com.android.vending

14968 4442376K 201732K 77360K 64520K 0K 0K 0K 0K com.android.settings

•VSS- Virtual Set Size 虚拟耗用内存（包含共享库占用的内存）

•RSS- Resident Set Size 实际使用物理内存（包含共享库占用的内存）

•PSS- Proportional Set Size 实际使用的物理内存（比例分配共享库占用的内存）

•USS- Unique Set Size 进程独自占用的物理内存（不包含共享库占用的内存）

•一般来说内存占用大小有如下规律：VSS >= RSS >= PSS >= USS

先上一个报错的anr 触摸无响应的log 信息。


01-01 19:00:49.033 779 871 I AnrManager: startAnrDump
01-01 19:00:49.033 779 871 I AnrManager: isANRFlowSkipped() AnrFlow = 0
01-01 19:00:49.034 779 871 I AnrManager: startAnrDump isSystemApp?true, isUserAMonkey?false ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30}
01-01 19:00:49.034 779 871 I AnrManager: enableTraceLog: false
01-01 19:00:49.042 779 871 I AnrManager: startAsyncDump: AnrDumpRecord{ 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: 7. Wait queue head age: 5513.7ms.) ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} IsCompleted:false IsCancelled:false }
01-01 19:00:49.045 779 871 I AnrManager: appNotResponding-got this lock: ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} 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: 7. Wait queue head age: 5513.7ms.),shuttingDown: false,notResponding: false,crashing: false
01-01 19:00:49.045 779 871 I AnrManager: dumpAnrDebugInfo begin: AnrDumpRecord{ 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: 7. Wait queue head age: 5513.7ms.) ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} IsCompleted:false IsCancelled:false }, isAsyncDump = false
01-01 19:00:49.046 779 871 I AnrManager: dumpAnrDebugInfoLocked: AnrDumpRecord{ 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: 7. Wait queue head age: 5513.7ms.) ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} IsCompleted:false IsCancelled:false }, isAsyncDump = false
01-01 19:00:49.127 779 7826 I AnrManager: sys/kernel/debug/binder/timeout_log isn't exist
01-01 19:00:49.176 779 871 I AnrManager: dumpStackTraces begin!
01-01 19:00:49.546 779 890 I AnrManager: START_ANR_DUMP_MSG: AnrDumpRecord{ 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: 7. Wait queue head age: 5513.7ms.) ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} IsCompleted:false IsCancelled:false }
01-01 19:00:49.547 779 890 I AnrManager: dumpAnrDebugInfo begin: AnrDumpRecord{ 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: 7. Wait queue head age: 5513.7ms.) ProcessRecord{343fdb0 1267:com.google.android.setupwizard/u0a30} IsCompleted:false IsCancelled:false }, isAsyncDump = true
01-01 19:01:06.185 779 871 I AnrManager: dumpStackTraces end!
01-01 19:01:06.367 779 871 I AnrManager: ANR in com.google.android.setupwizard (com.google.android.setupwizard/.account.KidPostSetupWrapper), time=325984
01-01 19:01:06.367 779 871 I AnrManager: 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: 7. Wait queue head age: 5513.7ms.)
01-01 19:01:06.367 779 871 I AnrManager: Load: 28.9 / 20.05 / 9.04
01-01 19:01:06.367 779 871 I AnrManager: Android time :[2018-01-01 12:01:06.19] [343.149]
01-01 19:01:06.367 779 871 I AnrManager: CPU usage from 279ms to -11697ms ago (2018-01-01 12:00:48.754 to 2018-01-01 12:01:00.730):
01-01 19:01:06.367 779 871 I AnrManager: 91% 779/system_server: 63% user + 27% kernel / faults: 25605 minor 100 major
01-01 19:01:06.367 779 871 I AnrManager: 43% 1026/com.android.systemui: 35% user + 8% kernel / faults: 15881 minor 52 major
01-01 19:01:06.367 779 871 I AnrManager: 27% 6587/com.google.android.gms: 23% user + 4.4% kernel / faults: 13386 minor 87 major
01-01 19:01:06.367 779 871 I AnrManager: 21% 375/surfaceflinger: 11% user + 9.6% kernel / faults: 530 minor 2 major
01-01 19:01:06.367 779 871 I AnrManager: 20% 1157/com.android.phone: 16% user + 4% kernel / faults: 8787 minor 14 major

.......

另外一种：11-05 13:40:49.534 951 974 I am_anr : [0,951,system,818462217,Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)]

我们从打印的信息网上推，一步一步从哪里开始即何时出发。

1 anr 的抓取流程图：