ANR原理篇 - ANR信息收集过程

Android百晓生

已于 2023-09-06 16:35:17 修改

阅读量937

点赞数

分类专栏： ANR 文章标签： android ANR 性能优化用户感知ANR 卡顿

于 2023-05-15 15:22:25 首次发布

本文链接：https://blog.csdn.net/qq_15509421/article/details/129998700

版权

ANR 专栏收录该内容

17 篇文章 4 订阅 ¥29.90 ¥99.00

订阅专栏

超级会员免费看

本文详细介绍了ANR(Access Not Responding)在Android系统中的信息收集过程，包括logcat记录、trace.txt文件内容、DropBox中的ANR信息，以及源码分析，涉及AMS.appNotResponding()、dumpStackTraces()等关键方法，旨在理解ANR发生时系统如何收集关键信息。

摘要由CSDN通过智能技术生成

系列文章目录

ANR概述

ANR基础篇 - Trace.txt文件分析

ANR基础篇 - Input系统

ANR基础篇 - 相关系统知识简介

ANR原理篇 - ANR原理总览

ANR原理篇 - ANR弹框是如何显示出来的

ANR原理篇 - service/broadcast/provider超时机制

ANR实战案例 1 - Google广告导致ANR解决

ANR实战案例 2 - 不同线程状态ANR示例

ANR实战案例 3 - 应用在部分低端机ANR优化案例

ANR工具篇 - 监控工具

ANR工具篇 - 分析工具

前言

一、ANR日志信息收集过程

发生ANR时，会有哪些日志，以及如何解读？
发生ANR的时候，会有3种形式的记录，分别记录不同的信息：

logcat中记录的日志。这里主要起到的是打印的作用，打印一些ANR的信息，以及会把一些CPU状态打印出来。
data/anr/目录下生成对应的ANR日志文件。这里面主要记录的是dump进程的信息。
dropbox中记录的信息。包括了logcat日志中的部分以及ANR文件中的部分。

ANR日志收集完整流程

2022-10-08 15:03:32.023 24194-24330/? W/InputDispatcher: Window ... is not responding. Waited 5007ms for MotionEvent    //InputDispatcher::onAnrLocked中，识别到输入事件响应超时
2022-10-08 15:03:32.023 24194-24330/? W/InputDispatcher: Canceling events ... it is unresponsive                        //InputDispatcher::cancelEventsForAnrLocked中，InputDispatcher进行ANR流程分法
2022-10-08 15:03:32.023 24194-24330/? I/WindowManager: ANR in Window{}                                                  //AnrController.java的notifyWindowUnresponsive中，window中超时，准备通知AMS
2022-10-08 15:03:32.146 24194-31707/? I/ActivityManager: dumpStackTraces pids={7705=true, 7740=true, ...}               //ActivityManagerService.java的dumpStackTraces中，准备收集的进程集合
2022-10-08 15:03:32.471 24194-31707/? I/ActivityManager: Dumping to /data/anr/anr_2022-10-08-15-03-32-471               //ActivityManagerService.java的dumpStackTraces中，准备通知APP收集ANR日志
2022-10-08 15:03:32.471 24194-31707/? I/ActivityManager: Collecting stacks for pid 31655                                //ActivityManagerService.java的dumpStackTraces中，待收集的进程PID
2022-10-08 15:03:32.472 24194-31707/? I/system_server: libdebuggerd_client: started dumping process 31655               //debuggerd_client.cpp的debuggerd_trigger_dump中，native中准备通知待收集的进程
2022-10-08 15:03:32.472 31655-31660/com.xt.client I/com.xt.client: Thread[6,tid=31660,...]: reacting to signal 3        //APP进程收到信号，准备开始写入
2022-10-08 15:03:32.568 31655-31660/com.xt.client I/com.xt.client: Wrote stack traces to tombstoned                     //APP进程写入完成，通知系统侧
2022-10-08 15:03:32.568 24194-31707/? I/system_server: libdebuggerd_client: done dumping process 31655                  //系统进程收到通知，进行保存
2022-10-08 15:03:32.589 24194-31707/? I/ActivityManager: Collecting stacks for pid 24194                                //ActivityManagerService.java dumpStackTraces中，准备开始收集下一个进程的PID，这个进程为系统进程system_server
2022-10-08 15:03:32.601 24194-31707/? I/system_server: libdebuggerd_client: started dumping process 24194               //debuggerd_client.cpp的debuggerd_trigger_dump中，native中准备通知待收集的进程
2022-10-08 15:03:32.603 24194-24202/? I/system_server: Thread[2,...]: reacting to signal 3                              //system_server进程收到信号，准备开始写入
2022-10-08 15:03:32.858 24194-24202/? I/system_server: Wrote stack traces to tombstoned                                 //system_server进程写入完成，通知系统侧
...继续收集其它java进程的信息
2022-10-08 15:03:34.972 24194-31707/? I/ActivityManager: Collecting stacks for native pid 660                           //准备收集native进程660的信息
2022-10-08 15:03:34.973 24194-31707/? I/system_server: libdebuggerd_client: started dumping process 660                 //debuggerd_client.cpp的debuggerd_trigger_dump中，native中准备通知待收集的进程
2022-10-08 15:03:34.974 660-660/? I/libc: Requested dump for pid 660 (binder:660_2)                                     //debuggerd_handler.cpp的log_signal_summary中，native中准备通知待收集的进程
...继续收集其它native进程的信息
2022-10-08 15:03:36.273 24194-31707/? I/ActivityManager: Done dumping                                                   //全部收集完成
2022-10-08 15:03:36.274 24194-31707/? E/ActivityManager: ANR in com.xt.client (com.xt.client/.MainActivity)             //打印发生ANR时收集到的日志

这里我们以Input类型为例，

InputDispatcher中识别到发生ANR了，通过回调java方法，通知到InputManagerService。如InputDispatcher开头的两行日志所记录。
InputManagerService中，根据WindowState找到对应的归属，先交给ActivityRecord处理，最终转交到AMS中。如WindowManager开头的一行日志所记录。
AMS中委托给AnrHelper.java进行处理，最终会通知到ProcessErrorStateRecord.java的appNotResponding方法，该方法中，会进行三个操作：
- 首先，收集需要dump的进程列表，包含java进程，native进程，其它进程，采集规则是发生ANR的进程+最近活动的进程。
- 其次，进行采集操作。这个会交给ActivityManagerService.java的dumpStackTraces方法执行。
- 最后，显示无响应的弹框。
采集日志会进入到ActivityManagerService.java的dumpStackTraces方法中，此时先打印ActivityManager开头的两行日志，分别代表着开始采集和生成日志文件。下面这两个日志分别记录将要采集的进程ID以及日志文件路径：

2022-10-08 15:03:32.146 24194-31707/? I/ActivityManager: dumpStackTraces pids={7705=true, 7740=true, ...}               //ActivityManagerService.java的dumpStackTraces中，准备收集的进程集合
2022-10-08 15:03:32.471 24194-31707/? I/ActivityManager: Dumping to /data/anr/anr_2022-10-08-15-03-32-471               //ActivityManagerService.java的dumpStackTraces中，准备通知APP收集ANR日志

因为需要dump多个进程的，所以开始采集以及采集完成的日志会有很多，如下面所示，分别代表开始采集，发送信号通知，收到信号通知，采集完成以及系统收到采集完成的通知。这种日志会经历很多轮。

2022-10-08 15:03:32.471 24194-31707/? I/ActivityManager: Collecting stacks for pid 31655                                //ActivityManagerService.java的dumpStackTraces中，待收集的进程PID
2022-10-08 15:03:32.472 24194-31707/? I/system_server: libdebuggerd_client: started dumping process 31655               //debuggerd_client.cpp的debuggerd_trigger_dump中，native中准备通知待收集的进程
2022-10-08 15:03:32.472 31655-31660/com.xt.client I/com.xt.client: Thread[6,tid=31660,...]: reacting to signal 3        //APP进程收到信号，准备开始写入
2022-10-08 15:03:32.568 31655-31660/com.xt.client I/com.xt.client: Wrote stack traces to tombstoned                     //APP进程写入完成，通知系统侧
2022-10-08 15:03:32.568 24194-31707/? I/system_server: libdebuggerd_client: done dumping process 31655                  //系统进程收到通知，进行保存

采集native的信息

2022-10-08 15:03:34.972 24194-31707/? I/ActivityManager: Collecting stacks for native pid 660                           //准备收集native进程660的信息
2022-10-08 15:03:34.973 24194-31707/? I/system_server: libdebuggerd_client: started dumping process 660                 //debuggerd_client.cpp的debuggerd_trigger_dump中，native中准备通知待收集的进程
2022-10-08 15:03:34.974 660-660/? I/libc: Requested dump for pid 660 (binder:660_2)                                     //debuggerd_handler.cpp的log_signal_summary中，native中准备通知待收集的进程

所有进程dump完成

2022-10-08 15:03:36.273 24194-31707/? I/ActivityManager: Done dumping                                                   //全部收集完成

1.1 logcat中信息记录

上面的流程采集完成后，会一次性打印采集到的ANR的信息，如下面所示（注释部分为logcat日志解读）：

2022-10-08 15:03:36.274 24194-31707/? E/ActivityManager: ANR in com.xt.client (com.xt.client/.MainActivity)
    PID: 31655    //进程ID
    Reason: Input dispatching timed out (dff7ad com.xt.client/com.xt.client.MainActivity (server) is not responding. Waited 5007ms for MotionEvent)    //原因
    Parent: com.xt.client/.MainActivity    //触发点
    ErrorId: bcef99f2-c232-4bee-bdd8-233b4ff598f0
    Frozen: false
    Load: 0.54 / 0.15 / 0.12        //ANR发生之前的1分钟，5分钟，15分钟CPU占用率。0.54代表0.54%
    ----- Output from /proc/pressure/memory -----
    some avg10=0.00 avg60=0.00 avg300=0.00 total=18377466
    full avg10=0.00 avg60=0.00 avg300=0.00 total=10458714
    ----- End output from /proc/pressure/memory -----
    //ANR发生之前的129秒内CPU占用率
    CPU usage from 129271ms to 0ms ago (2022-10-08 15:01:22.846 to 2022-10-08 15:03:32.116):
      //user代表用户态占用，kernel代表内核态占用
      1.7% 24194/system_server: 1.2% user + 0.5% kernel / faults: 3611 minor
      1.5% 689/surfaceflinger: 1.1% user + 0.4% kernel / faults: 441 minor
      1.4% 24426/com.android.systemui: 1% user + 0.3% kernel / faults: 2682 minor
      1% 28207/kworker/u16:6: 0% user + 1% kernel / faults: 18 minor
      0.8% 31505/kworker/u16:3: 0% user + 0.8% kernel
      0.7% 27789/kworker/u16:1: 0% user + 0.7% kernel / faults: 2 minor
      0.6% 29978/com.tencent.mm: 0.1% user + 0.4% kernel / faults: 66 minor
      0.6% 1122/vendor.google.wifi_ext@1.0-service-vendor: 0.3% user + 0.2% kernel / faults: 1190 minor
      0.3% 24523/com.breel.wallpapers20a: 0.2% user + 0% kernel / faults: 1291 minor
      0.4% 24828/com.google.android.apps.nexuslauncher: 0.3% user + 0% kernel / faults: 1984 minor
      0.1% 691/android.hardware.graphics.composer@2.4-service-sm8150: 0% user + 0% kernel / faults: 133 minor
      0.3% 18902/com.google.android.gms.persistent: 0.2% user + 0.1% kernel / faults: 2221 minor
      0.3% 30388/com.tencent.mm:tools: 0.2% user + 0% kernel / faults: 93 minor
      ...

具体解释如下：
在这里插入图片描述

1.2 trace.txt文件中记录的信息

由于trace.txt文件是ANR查看分析的重点，且内容较多，故作为单独的一个章节整理输出详细查看：ANR基础篇 - Trace.txt文件分析

1.3 DropBox中的ANR信息

dropBox中的日志文件更像是一个综合体，包括了logcat日志中的部分以及ANR文件中的部分。
源码中ProcessErrorStateRecord的appNotResponding方法中，会通过以下的方法，把report信息和traceFile中的信息进行记录。report信息基本上就是上面logcat中的部分。

mService.addErrorToDropBox("anr", mApp, mApp.processName, activityShortComponentName,
                parentShortComponentName, parentPr, null, report.toString(), tracesFile,
                null, new Float(loadingProgress), incrementalMetrics, errorId);

文件位置是：/data/system/dropbox/data_app_anr@1670396615724.txt.gz
是一个压缩文件，解析后就是我们想要的内容了，大体的格式如下：

Process: com.beantechs.apm
PID: 10589
Flags: 0x20e8bf46
Package: com.xxx.apm v1 (1.0)
Foreground: Yes
Activity: com.xxx.apm/.TestActivity
Subject: 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: 4.  Wait queue head age: 5571.8ms.)
Build: qti/gwm/gwm:9/PQ1A.190105.004/bean08231515:userdebug/test-keys
 
CPU usage from 141069ms to 0ms ago (2022-12-07 15:01:10.951 to 2022-12-07 15:03:32.020):
  20% 6354/adbd: 1.7% user + 18% kernel / faults: 4493599 minor
  5.8% 322/logd: 1.7% user + 4% kernel / faults: 26 minor
  4.3% 514/android.hardware.sensors@1.0-service: 0.6% user + 3.7% kernel
  3.9% 385/vendor.ts.systemlog@1.0-service: 1.7% user + 2.1% kernel / faults: 281 minor
  3.4% 497/android.hardware.audio@2.0-service.rbgwm: 0.9% user + 2.4% kernel
  3.2% 1020/system_server: 1.3% user + 1.9% kernel / faults: 21547 minor 1 major
  3.2% 543/audioserver: 1.2% user + 1.9% kernel / faults: 4052 minor
  3.2% 26582/kworker/u16:1: 0% user + 3.2% kernel
  2.2% 4415/com.beantechs.datapipeline: 1.5% user + 0.7% kernel / faults: 41778 minor
  2.1% 4442/com.lx.usbaudiohid: 1% user + 1% kernel / faults: 2 minor
  2% 3376/com.beantechs.intelligentvehiclecontrol: 1.3% user + 0.7% kernel / faults: 5915 minor
  1.8% 9937/kworker/u17:1: 0% user + 1.8% kernel
 ...
10% TOTAL: 3.2% user + 6.4% kernel + 0% iowait + 0.7% irq + 0.1% softirq
 
----- pid 10589 at 2022-12-07 15:03:32 -----
Cmd line: com.xxxx.apm

详细请参看DropBox系列-安卓DropBox介绍

收集进程信息

ANR发生的原因，有时候并不是APP自身导致的，和其他进程也有关系。比如其他进程耗尽CPU资源，导致发生ANR的APP的任务无法正常执行。所以，发生ANR后，收集原因时，并不能单纯的只收集发生ANR的那个APP进程。
appNotResponding方法中，有两个集合，分别是firstPids和lastPids，分别收集

ArrayList<Integer> firstPids = new ArrayList<>(5);
SparseArray<Boolean> lastPids = new SparseArray<>(20);

firstPids中会加入以下类型的进程ID：

发生ANR的进程PID；
发生ANR的进程的父进程PID；
系统进程的PID；
最近使用到并且还存活的进程PID；
存在被处理过的Activity的进程PID，这个说实在的，我没太理解，不过不影响主流程，就先忽略。

二、ANR的信息收集过程源码分析

无论是四大组件或者进程等只要发生ANR，最终都会调用AMS.appNotResponding()方法，下面从这个方法说起。

1. AMS.appNotResponding

final void appNotResponding(ProcessRecord app, ActivityRecord activity, ActivityRecord parent, boolean aboveSystem, final String annotation) {
    ...
    updateCpuStatsNow(); //第一次 更新cpu统计信息
    synchronized (this) {
      //PowerManager.reboot() 会阻塞很长时间，因此忽略关机时的ANR
      if (mShuttingDown) {
          return;
      } else if (app.notResponding) {
          return;
      } else if (app.crashing) {
          return;
      }
      //记录ANR到EventLog
      EventLog.writeEvent(EventLogTags.AM_ANR, app.userId, app.pid,
              app.processName, app.info.flags, annotation);
              
      // 将当前进程添加到firstPids
      firstPids.add(app.pid);
      int parentPid = app.pid;
      
      //将system_server进程添加到firstPids
      if (MY_PID != app.pid && MY_PID != parentPid) firstPids.add(MY_PID);
      
      for (int i = mLruProcesses.size() - 1; i >= 0; i--) {
          ProcessRecord r = mLruProcesses.get(i);
          if (r != null && r.thread != null) {
              int pid = r.pid;
              if (pid > 0 && pid != app.pid && pid != parentPid && pid != MY_PID) {
                  if (r.persistent) {
                      firstPids.add(pid); //将persistent进程添加到firstPids
                  } else {
                      lastPids.put(pid, Boolean.TRUE); //其他进程添加到lastPids
                  }
              }
          }
      }
    }
    
    // 记录ANR输出到main log
    StringBuilder info = new StringBuilder();
    info.setLength(0);
    info.append("ANR in ").append(app.processName);
    if (activity != null && activity.shortComponentName != null) {
        info.append(" (").append(activity.shortComponentName).append(")");
    }
    info.append("\n");
    info.append("PID: ").append(app.pid).append("\n");
    if (annotation != null) {
        info.append("Reason: ").append(annotation).append("\n");
    }
    if (parent != null && parent != activity) {
        info.append("Parent: ").append(parent.shortComponentName).append("\n");
    }
    
    //创建CPU tracker对象
    final ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(true);
    //输出traces信息【见小节2】
    File tracesFile = dumpStackTraces(true, firstPids, processCpuTracker, 
            lastPids, NATIVE_STACKS_OF_INTEREST);
            
    updateCpuStatsNow(); //第二次更新cpu统计信息
    //记录当前各个进程的CPU使用情况
    synchronized (mProcessCpuTracker) {
        cpuInfo = mProcessCpuTracker.printCurrentState(anrTime);
    }
    //记录当前CPU负载情况
    info.append(processCpuTracker.printCurrentLoad());
    info.append(cpuInfo);
    //记录从anr时间开始的Cpu使用情况
    info.append(processCpuTracker.printCurrentState(anrTime));
    //输出当前ANR的reason，以及CPU使用率、负载信息
    Slog.e(TAG, info.toString()); 
    
    //将traces文件 和 CPU使用率信息保存到dropbox，即data/system/dropbox目录
    addErrorToDropBox("anr", app, app.processName, activity, parent, annotation,
            cpuInfo, tracesFile, null);

    synchronized (this) {
        ...
        //后台ANR的情况, 则直接杀掉
        if (!showBackground && !app.isInterestingToUserLocked() && app.pid != MY_PID) {
            app.kill("bg anr", true);
            return;
        }

        //设置app的ANR状态，病查询错误报告receiver
        makeAppNotRespondingLocked(app,
                activity != null ? activity.shortComponentName : null,
                annotation != null ? "ANR " + annotation : "ANR",
                info.toString());

        //重命名trace文件
        String tracesPath = SystemProperties.get("dalvik.vm.stack-trace-file", null);
        if (tracesPath != null && tracesPath.length() != 0) {
            //traceRenameFile = "/data/anr/traces.txt"
            File traceRenameFile = new File(tracesPath);
            String newTracesPath;
            int lpos = tracesPath.lastIndexOf (".");
            if (-1 != lpos)
                // 新的traces文件= /data/anr/traces_进程名_当前日期.txt
                newTracesPath = tracesPath.substring (0, lpos) + "_" + app.processName + "_" + mTraceDateFormat.format(new Date()) + tracesPath.substring (lpos);
            else
                newTracesPath = tracesPath + "_" + app.processName;

            traceRenameFile.renameTo(new File(newTracesPath));
        }
                
        //弹出ANR对话框
        Message msg = Message.obtain();
        HashMap<String, Object> map = new HashMap<String, Object>();
        msg.what = SHOW_NOT_RESPONDING_MSG;
        msg.obj = map;
        msg.arg1 = aboveSystem ? 1 : 0;
        map.put("app", app);
        if (activity != null) {
            map.put("activity", activity);
        }
        
        //向ui线程发送，内容为SHOW_NOT_RESPONDING_MSG的消息
        mUiHandler.sendMessage(msg);
    }
    
}

当发生ANR时, 会按顺序依次执行:

输出ANR Reason信息到EventLog. 也就是说ANR触发的时间点最接近的就是EventLog中输出的am_anr信息;
收集并输出重要进程列表中的各个线程的traces信息，该方法较耗时; 【见小节2】
输出当前各个进程的CPU使用情况以及CPU负载情况;
将traces文件和 CPU使用情况信息保存到dropbox，即data/system/dropbox目录
根据进程类型,来决定直接后台杀掉,还是弹框告知用户.

ANR输出重要进程的traces信息，这些进程包含:

firstPids队列：第一个是ANR进程，第二个是system_server，剩余是所有persistent进程；
Native队列：是指/system/bin/目录的mediaserver,sdcard 以及surfaceflinger进程；
lastPids队列: 是指mLruProcesses中的不属于firstPids的所有进程。

2. AMS.dumpStackTraces

public static File dumpStackTraces(boolean clearTraces, ArrayList<Integer> firstPids, ProcessCpuTracker processCpuTracker, SparseArray<Boolean> lastPids, String[] nativeProcs) {
    //默认为 data/anr/traces.txt
    String tracesPath = SystemProperties.get("dalvik.vm.stack-trace-file", null);
    if (tracesPath == null || tracesPath.length() == 0) {
        return null;
    }

    File tracesFile = new File(tracesPath);
    try {
        //当clearTraces，则删除已存在的traces文件
        if (clearTraces && tracesFile.exists()) tracesFile.delete();
        //创建traces文件
        tracesFile.createNewFile();
        FileUtils.setPermissions(tracesFile.getPath(), 0666, -1, -1);
    } catch (IOException e) {
        return null;
    }
    //输出trace内容【见小节3】
    dumpStackTraces(tracesPath, firstPids, processCpuTracker, lastPids, nativeProcs);
    return tracesFile;
}

这里会保证data/anr/traces.txt文件内容是全新的方式，而非追加。

3. AMS.dumpStackTraces

private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstPids, ProcessCpuTracker processCpuTracker, SparseArray<Boolean> lastPids, String[] nativeProcs) {
    FileObserver observer = new FileObserver(tracesPath, FileObserver.CLOSE_WRITE) {
        @Override
        public synchronized void onEvent(int event, String path) { notify(); }
    };

    try {
        observer.startWatching();

        //首先，获取最重要进程的stacks
        if (firstPids != null) {
            try {
                int num = firstPids.size();
                for (int i = 0; i < num; i++) {
                    synchronized (observer) {
                        //向目标进程发送signal来输出traces
                        Process.sendSignal(firstPids.get(i), Process.SIGNAL_QUIT);
                        observer.wait(200);  //等待直到写关闭，或者200ms超时
                    }
                }
            } catch (InterruptedException e) {
                Slog.wtf(TAG, e);
            }
        }

        //下一步，获取native进程的stacks
        if (nativeProcs != null) {
            int[] pids = Process.getPidsForCommands(nativeProcs);
            if (pids != null) {
                for (int pid : pids) {
                    //输出native进程的trace【见小节4】
                    Debug.dumpNativeBacktraceToFile(pid, tracesPath);
                }
            }
        }

        if (processCpuTracker != null) {
            processCpuTracker.init();
            System.gc();
            processCpuTracker.update();
            synchronized (processCpuTracker) {
                processCpuTracker.wait(500); //等待500ms
            }
            //测量CPU使用情况
            processCpuTracker.update();

            //从lastPids中选取CPU使用率 top 5的进程，输出这些进程的stacks
            final int N = processCpuTracker.countWorkingStats();
            int numProcs = 0;
            for (int i=0; i<N && numProcs<5; i++) {
                ProcessCpuTracker.Stats stats = processCpuTracker.getWorkingStats(i);
                if (lastPids.indexOfKey(stats.pid) >= 0) {
                    numProcs++;
                    synchronized (observer) {
                        Process.sendSignal(stats.pid, Process.SIGNAL_QUIT);
                        observer.wait(200); 
                    }
                }
            }
        }
    } finally {
        observer.stopWatching();
    }
}

该方法的主要功能，依次输出：

收集firstPids进程的stacks；
- 第一个是发生ANR进程；
- 第二个是system_server；
- mLruProcesses中所有的persistent进程；
收集Native进程的stacks；(dumpNativeBacktraceToFile)
- 依次是mediaserver,sdcard,surfaceflinger进程；
- 收集lastPids进程的stacks;；
- 依次输出CPU使用率top 5的进程；

Tips: firstPids列表中的进程, 两个进程之间会休眠200ms, 可见persistent进程越多,则时间越长. top 5进程的traces过程中, 同样是间隔200ms, 另外进程使用情况的收集也是比较耗时.

5.dump_backtrace_to_file

debugger.c

int dump_backtrace_to_file(pid_t tid, int fd) {
    return dump_backtrace_to_file_timeout(tid, fd, 0);
}

int dump_backtrace_to_file_timeout(pid_t tid, int fd, int timeout_secs) {
  //通过socket向服务端发送dump backtrace的请求
  int sock_fd = make_dump_request(DEBUGGER_ACTION_DUMP_BACKTRACE, tid, timeout_secs);
  if (sock_fd < 0) {
    return -1;
  }

  int result = 0;
  char buffer[1024];
  ssize_t n;
  //阻塞等待，从sock_fd中读取到服务端发送过来的数据，并写入buffer
  while ((n = TEMP_FAILURE_RETRY(read(sock_fd, buffer, sizeof(buffer)))) > 0) {
    //再将buffer数据输出到traces.txt文件
    if (TEMP_FAILURE_RETRY(write(fd, buffer, n)) != n) {
      result = -1;
      break;
    }
  }
  close(sock_fd);
  return result;
}

这个过程主要是通过向debuggerd守护进程发送命令DEBUGGER_ACTION_DUMP_BACKTRACE， debuggerd收到该命令，在子进程中调用 dump_backtrace()来输出backtrace.

小节

触发ANR时系统会输出关键信息：(这个较耗时,可能会有10s)

将am_anr信息,输出到EventLog.(ANR开始起点看EventLog)
获取重要进程trace信息，保存到/data/anr/traces.txt；(会先删除老的文件)
- Java进程的traces;
- Native进程的traces;
ANR reason以及CPU使用情况信息，输出到main log;
再将CPU使用情况和进程trace文件信息，再保存到/data/system/dropbox；

整个过程中进程Trace的输出是最为核心的环节，Java和Native进程采用不同的策略，详细可参考如下两篇文章：
解读Java进程的Trace文件
 Native进程之Trace原理

附录

另外一个机型MainLog：

ANR in com.xxx.xxx (com.xxx.xxx/com.xxx.xxx.guide.ControllerActivity), time=220754557
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: 50.  Wait queue head age: 8516.5ms.)
Load: 13.3 / 13.12 / 13.33
Android time :[2023-04-06 20:23:40.93] [220757.938]
CPU usage from 286390ms to 0ms ago (2023-04-06 20:18:51.166 to 2023-04-06 20:23:37.555):
16% 1054/system_server: 11% user + 4.7% kernel / faults: 55130 minor 3 major
3.2% 26899/kworker/1:3: 0% user + 3.2% kernel
5.5% 3885/com.transsion.phonemaster: 3.7% user + 1.7% kernel / faults: 22973 minor
3.7% 345/surfaceflinger: 1.6% user + 2.1% kernel / faults: 3846 minor
3.4% 8204/adbd: 0.8% user + 2.6% kernel / faults: 59430 minor
2.4% 32343/com.android.vending: 1.8% user + 0.6% kernel / faults: 20158 minor
2.8% 2248/com.google.android.gms: 2.2% user + 0.6% kernel / faults: 10893 minor
2.5% 1441/com.android.systemui: 2% user + 0.5% kernel / faults: 22221 minor 1 major
2.4% 1953/com.google.android.gms.persistent: 1.9% user + 0.5% kernel / faults: 5479 minor
2.3% 222/exe_cq: 0% user + 2.3% kernel
1.9% 224/mmcqd/0: 0% user + 1.9% kernel
1.7% 301/logd: 0.5% user + 1.1% kernel / faults: 302 minor
1.7% 344/servicemanager: 0.7% user + 0.9% kernel / faults: 2 minor
1.3% 217/hps_main: 0% user + 1.3% kernel
1.1% 22608/logcat: 0.5% user + 0.6% kernel / faults: 1 minor
1.1% 1691/com.android.phone: 0.8% user + 0.2% kernel / faults: 3205 minor
0.6% 3804/com.android.defcontainer: 0.2% user + 0.3% kernel / faults: 1979 minor
0.8% 478/audioserver: 0.6% user + 0.2% kernel / faults: 55 minor
0.6% 2162/com.transsion.hilauncher: 0.4% user + 0.1% kernel / faults: 22770 minor 4 major
0.4% 481/installd: 0% user + 0.3% kernel / faults: 107 minor
0.7% 455/media.codec: 0.4% user + 0.3% kernel / faults: 3 minor
0.7% 485/mediaserver: 0.4% user + 0.2% kernel / faults: 649 minor
0.6% 1396/tx_thread: 0% user + 0.6% kernel
0.5% 197/disp_idlemgr: 0% user + 0.5% kernel
0.5% 452/aal: 0.1% user + 0.3% kernel
0.4% 2214/com.google.process.gapps: 0.3% user + 0.1% kernel / faults: 7199 minor
0.1% 19326/android.process.acore: 0.1% user + 0% kernel / faults: 15780 minor
0.3% 7/rcu_preempt: 0% user + 0.3% kernel
0.3% 8/rcu_sched: 0% user + 0.3% kernel
0.3% 3912/kworker/u16:2: 0% user + 0.3% kernel
0.2% 69/dvfs_nfy: 0% user + 0.2% kernel
0.1% 482/keystore: 0.1% user + 0% kernel / faults: 57 minor
0.1% 3791/com.google.android.packageinstaller: 0% user + 0% kernel / faults: 2037 minor
0.2% 29339/kworker/u17:3: 0% user + 0.2% kernel
0.2% 31900/kworker/u16:1: 0% user + 0.2% kernel
0.2% 3350/kworker/u17:0: 0% user + 0.2% kernel
0.2% 30383/kworker/u17:4: 0% user + 0.2% kernel
0.1% 436/jbd2/dm-1-8: 0% user + 0.1% kernel
0.1% 26193/kworker/u16:0: 0% user + 0.1% kernel
0.1% 132/pbm: 0% user + 0.1% kernel
0.1% 417/disp_queue_P0: 0% user + 0.1% kernel
0.1% 401/dmcrypt_write: 0% user + 0.1% kernel
0.1% 14983/com.tencent.mobileqq:MSF: 0% user + 0% kernel / faults: 217 minor
0.1% 346/mtkmal: 0.1% user + 0% kernel
0.1% 29902/kworker/0:4: 0% user + 0.1% kernel
0.1% 343/lmkd: 0% user + 0.1% kernel
0.1% 10/migration/0: 0% user + 0.1% kernel
0.1% 1401/com.emoji.keyboard.touchpal: 0% user + 0% kernel / faults: 1144 minor 1 major
0.1% 202/disp_delay_trig: 0% user + 0.1% kernel
0.1% 248/charger_thread: 0% user + 0.1% kernel
0.1% 4726/kworker/u17:2: 0% user + 0.1% kernel
0% 27873/kworker/4:0: 0% user + 0% kernel
0.1% 73/cfinteractive: 0% user + 0.1% kernel
0.1% 11/migration/1: 0% user + 0.1% kernel
0% 15/migration/2: 0% user + 0% kernel
0% 182/irq/682-rt5081_: 0% user + 0% kernel
0% 74/ion_mm_heap: 0% user + 0% kernel
0% 1400/wpa_supplicant: 0% user + 0% kernel / faults: 1 minor
0% 486/netd: 0% user + 0% kernel / faults: 858 minor
0% 1831/ged_srv: 0% user + 0% kernel / faults: 1 minor
0% 22869/kworker/u16:

参考：
ANR显示和日志生成原理讲解
 理解Android ANR的信息收集过程

Android百晓生

关注

0
点赞
踩
2

收藏

觉得还不错? 一键收藏
0
评论
ANR原理篇 - ANR信息收集过程

发生ANR时，会有哪些日志，以及如何解读？logcat中记录的日志。这里主要起到的是打印的作用，打印一些ANR的信息，以及会把一些CPU状态打印出来。data/anr/目录下生成对应的ANR日志文件。这里面主要记录的是dump进程的信息。dropbox中记录的信息。包括了logcat日志中的部分以及ANR文件中的部分。ANR显示和日志生成原理讲解理解Android ANR的信息收集过程。
复制链接

扫一扫

专栏目录