Android ANR日志分析

sancaiodm Bug异常与ODM定制 2022-06-17 1659 0

      ANR,是“Application Not Responding”的缩写,即“应用程序无响应”。在Android中,ActivityManagerService(简称AMS)和WindowManagerService(简称WMS)会监测应用程序的响应时间,如果应用程序主线程(即UI线程)在超时时间内对输入事件没有处理完毕,或者对特定操作没有执行完毕,就会出现ANR。对于输入事件没有处理完毕产生的ANR,Android会显示一个对话框,提示用户当前应用程序没有响应,用户可以选择继续等待或者关闭这个应用程序(也就是杀掉这个应用程序的进程)。

以下四个条件可以产生ANR:

    InputDispatching Timeout: 5s内无法响应屏幕触摸事件或键盘输入事件。

    BroadcastQueue Timeout: BroadcastReceiver的事件(onRecieve方法)在规定时间内没处理完成(前台规定时间:10s,后台规定时间:60s)。

    Service Timeout: 规定时间未完成启动 Timeout executing service(前台:20s 后台:200s)。

    ContentProvider Timeout: ContentProvider的publish在10s内没进行完


ANR窗口的弹窗界面类位置:

aosp/frameworks/base/services/core/java/com/android/server/am/AppNotRespondingDialog.java

造成ANR的原因

  1. 应用在主线程上执行耗时的I/O的操作。

  2. 应用在主线程上进行长时间的计算。

  3. 主线程在对另一个进程进行同步 binder 调用,而后者需要很长时间才能返回。(如果我们知道调用远程方法需要很长时间,我们应该避免在主线程调用)

  4. 主线程处于阻塞状态,主动睡眠,或者等待其他线程上的同步方法或者同步代码块执行完毕。

  5. 主线程与其他线程之间发生死锁。

上述原因都会造成主线程被长时间占用,导致无法响应用户的操作,从而造成ANR。

注意:主线程做耗时操作本身是不会产生ANR的,导致ANR的根本还是应用程序无法在一定时间内响应用户的操作。因为主线程被耗时操作占用了,主线程无法对下一个操作进行响应才会ANR,没有需要响应的操作自然就不会产生ANR,或者应该这样说:主线程做耗时操作,非常容易引发ANR。


线程的状态是native则表示当前正在执行jni,


/data/anr/xxx

/data/tombstones/tombstone_X

/data/system/dropbox/



使用bugreport命令,需要在开发者选项里面启用提交错误报告

adb pull /data/anr/bugreport-traces.txt


tombstone,俗称“墓碑”

因为android系统是运行在Linux Kernel内核之上的,当内核出现异常,则内核异常机制会分辨出是什么原因,处理不了的直接panic。而对于运行在Linux Kernel内核之上的android系统,如果出现异常,一般会自动重启android层的,这就导致问题很难复现定位debug,则当android层出现异常,通常会将进程的上下文信息保存到tombstone(墓碑)中,

adb bugreport


ADLVIK THREADS (99)  //当前进程总数99个线程

"main" prio=5 tid=1 Native    //线程名main   主线程调用栈

2.1 ANR重现

这里使用生成一个按钮跳转到ANRTestActivity,在后者的onCreate()中主线程休眠20秒:

@Overrideprotected void onCreate(@Nullable Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    setContentView(R.layout.activity_anr_test);
    // 这是Android提供线程休眠函数,与Thread.sleep()最大的区别是
        // 该使用该函数不会抛出InterruptedException异常。   
         SystemClock.sleep(20 * 1000);
         
}

//ANR前后cpu的使用情况

//如果CPU使用量接近100%,说明当前设备很忙,有可能是CPU饥饿导致ANR

//如果CPU使用量很少,说明主线程被block了

//如果IOwait很高,说明主线程在进行I/O操作

----- pid 28207 at 2020-12-03 17:30:41 -----
Cmd line: com.example.produceanr
//进程号、ANR发生时间和进程名称
DALVIK THREADS (14):  当前进程总数14个线程
//主线程调用栈
"main" prio=5 tid=1 Sleeping
//线程名、线程优先级、线程号、线程当前状态  
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x76e543c8 self=0x6ffcf70000
  | sysTid=28207 nice=-10 cgrp=default sched=0/0 handle=0x6ffe4d7ed0
  | state=S schedstat=( 1106323008 54303290 408 ) utm=97 stm=13 core=4 HZ=100
  | stack=0x7fcbd76000-0x7fcbd78000 stackSize=8192KB
  | held mutexes=
  at java.lang.Thread.sleep(Native method)
  - sleeping on <0x0a2aeaaf> (a java.lang.Object)
  at java.lang.Thread.sleep(Thread.java:440)
  - locked <0x0a2aeaaf> (a java.lang.Object)
  at java.lang.Thread.sleep(Thread.java:356)
  at com.example.produceanr.MainActivity$1.onClick(MainActivity.java:23)



如出现ANR问题 ,可以Main log中可以搜索ANR in 关键字,


FATAL,leaked, block,Pid id XXX,crash,DALVIK THREADS, OOM,unfinished died


ANR问题:

出现ANR应当提供traces.txt文件,直接在文件中搜索 关键字。锁定三个方向:memoryleak(是否为低内存),CPU block(CPU使用率过高)、iowait(IO流使用过于频繁)

(1)memoryleak:首先根据Android log搜索低内存相关 low_memory 关键字,以确定是否存在低内存现象

(2)CPU block:搜索对应包出现ANR前后 TOTAL 关键字前的百分比,若百分比接近100% 说明CPU饥饿导致了ANR:

(3)iowait:搜索iowait 关键字查看出现ANR前的百分比,若百分比过高,说明I/O流使用过于频繁导致ANR,此项需修改相关数据库的加载流程,如下:




"main" prio=5 tid=1 Sleeping
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x7682ab30 self=0x7bd3815c00
  | sysTid=6317 nice=-10 cgrp=default sched=0/0 handle=0x7c59fc8548
  | state=S schedstat=( 1009468742 32888019 224 ) utm=91 stm=9 core=4 HZ=100
  | stack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB
  | held mutexes=

线程名:main
线程优先级:prio=5  //prio  -> java thread priority default is 5, (nice =0, linux thread priority 120), domain is [1,10]

线程ID: tid=1
线程状态:Sleeping  //ZOMBIE,  RUNNABLE, TIMED_WAIT, MONITOR, WAIT, INITALIZING,STARTING, NATIVE, VMWAIT, SUSPENDED,UNKNOWN

线程组名称:group="main"
线程被挂起的次数:sCount=1
线程被调试器挂起的次数:dsCount=0
线程的java的对象地址:obj= 0x7682ab30
线程本身的Native对象地址:self=0x7bd3815c00

线程调度信息:
Linux系统中内核线程ID: sysTid=6317与主线程的进程号相同
线程调度优先级:nice=-10
线程调度组:cgrp=default
线程调度策略和优先级:sched=0/0
线程处理函数地址:handle= 0x7c59fc8548

线程的上下文信息:
线程调度状态:state=S
线程在CPU中的执行时间、线程等待时间、线程执行的时间片长度:schedstat=(1009468742 32888019 224)
线程在用户态中的调度时间值:utm=91
线程在内核态中的调度时间值:stm=9
最后执行这个线程的CPU核序号:core=4

线程的堆栈信息:
堆栈地址和大小:stack=0x7ff27e1000-0x7ff27e3000 stackSize=8MB


“androidosnet ”daemon prio=5 tid=6 VMWAIT   //如此,当线程名称后面标识是 daemon,说明这一个守护线程,可以不用管

“JDWP ”daemon prio=5 tid=6 VMWAIT   //如此,JDWP线程是支持虚拟机调试的线程,不需要关心

"Signal Catcher" daemon prio=5 tid=4 RUNABLE  //该线程是负责接收与处理kernel发送的各种信号,该线程不需要关心


Thread.java中定义的状态

Thread.cpp中定义的状态

说明

TERMINATED

ZOMBIE

线程死亡,终止运行

RUNNABLE

RUNNING/RUNNABLE

线程可运行或正在运行

TIMED_WAITING

TIMED_WAIT

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

BLOCKED

MONITOR

线程阻塞,等待获取对象锁

WAITING

WAIT

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

NEW

INITIALIZING

新建,正在初始化,为其分配资源

NEW

STARTING

新建,正在启动

RUNNABLE

NATIVE

正在执行JNI本地函数

WAITING

VMWAIT

正在等待VM资源

RUNNABLE

SUSPENDED

线程暂停,通常是由于GC或debug被暂停


UNKNOWN

未知状态


评论