Android Framework（六）——ANR机制从产生到消费

最近看了几篇关于ANR机制的文章，本篇文章来源码跟踪一下ANR消息的产生、消费与dump的全过程，彻底理解ANR出现的原因，并且讨论如何监控ANR的产生。

ANR机制原理

ANR（Application Not Responding）机制是Android系统中一种监控用户App是否长时间未响应的一种机制，类似于Windows系统中的“程序未响应”。

既然是监控耗时，类似于我们监控一个方法的执行时间，一定会在方法执行前做一些记录，然后与方法执行结束后进行对比，ANR中也是类似的。

触发场景

那么哪些场景下会导致ANR呢？主要有以下几种情况：

  1. KEY_DISPATCHING_TIMEOUT：输入事件分发超过5秒，包括触摸事件与按键事件。
  2. BROADCAST_FG_TIMEOUT：前台广播接收者在10秒内未执行完成。
  3. BROADCAST_BG_TIMEOUT：后台广播接收者在60秒内未执行完成。
  4. SERVICE_TIMEOUT：前台服务在20秒内未执行完某一生命周期。
  5. SERVICE_BACKGROUND_TIMEOUT：后台服务在200秒内未执行完某一生命周期。
  6. CONTENT_PROVIDER_PUBLISH_TIMEOUT：内容提供者在publish时超过10秒。

以上时间是基于Android 10.0源码的，具体时间定义在ActivityManagerService.java、ActivityTaskManagerService和ActiveServices.java中：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
[ActivityManagerService.java]
// How long we wait for an attached process to publish its content providers
// before we decide it must be hung.
static final int CONTENT_PROVIDER_PUBLISH_TIMEOUT = 10*1000;

// How long we allow a receiver to run before giving up on it.
static final int BROADCAST_FG_TIMEOUT = 10*1000;
static final int BROADCAST_BG_TIMEOUT = 60*1000;

[ActivityTaskManagerService.java]
// How long we wait until we timeout on key dispatching.
public static final int KEY_DISPATCHING_TIMEOUT_MS = 5 * 1000;

[ActiveServices.java]
// How long we wait for a service to finish executing.
static final int SERVICE_TIMEOUT = 20*1000;

// How long we wait for a service to finish executing.
static final int SERVICE_BACKGROUND_TIMEOUT = SERVICE_TIMEOUT * 10;

下面以后台服务为例，分析ANR机制的触发流程。

触发流程

我们从服务的启动过程来寻找ANR相关代码，由于代码比较多，并且启动Service的过程与Activity的启动很类似，而前面已经写了篇文章来详细讲解Activity的启动过程了，所以这里选择跳过部分代码。

ActiveServices#realStartServiceLocked

直接来到ActiveServices中的realStartServiceLocked方法中：

frameworks/base/services/core/java/com/android/server/am/ActiveServices.java

1
2
3
4
5
6
7
8
9
10
11
12
private final void realStartServiceLocked(ServiceRecord r,
        ProcessRecord app, boolean execInFg) throws RemoteException {
  
    ···
      
    final boolean newService = app.services.add(r);
    bumpServiceExecutingLocked(r, execInFg, "create");
    mAm.updateLruProcessLocked(app, false, null);
    updateServiceForegroundLocked(r.app, /* oomAdj= */ false);
    mAm.updateOomAdjLocked(OomAdjuster.OOM_ADJ_REASON_START_SERVICE);
     ···
}

此方法首先调用了bumpServiceExecutingLocked，这里有我们寻找的代码，跟进。

ActiveServices#bumpServiceExecutingLocked

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
private final void bumpServiceExecutingLocked(ServiceRecord r, boolean fg, String why) {
  
    ···

    // 记录当前时间
    long now = SystemClock.uptimeMillis();
    if (r.executeNesting == 0) {
        r.executeFg = fg;
        ServiceState stracker = r.getTracker();
        if (stracker != null) {
            stracker.setExecuting(true, mAm.mProcessStats.getMemFactorLocked(), now);
        }
        if (r.app != null) {
            r.app.executingServices.add(r);
            r.app.execServicesFg |= fg;
            if (timeoutNeeded && r.app.executingServices.size() == 1) {
                // 
                scheduleServiceTimeoutLocked(r.app);
            }
        }
    } else if (r.app != null && fg && !r.app.execServicesFg) {
        r.app.execServicesFg = true;
        if (timeoutNeeded) {
            // 
            scheduleServiceTimeoutLocked(r.app);
        }
    }
    ···
}

这里无论是哪个if分支都调用了scheduleServiceTimeoutLocked方法，看名字猜测其余Service的超时有关，继续跟进。

ActiveServices#scheduleServiceTimeoutLocked

1
2
3
4
5
6
7
8
9
10
11
void scheduleServiceTimeoutLocked(ProcessRecord proc) {
    if (proc.executingServices.size() == 0 || proc.thread == null) {
        return;
    }
    // mAm为ActivityManager
    Message msg = mAm.mHandler.obtainMessage(
            ActivityManagerService.SERVICE_TIMEOUT_MSG);
    msg.obj = proc;
    mAm.mHandler.sendMessageDelayed(msg,
            proc.execServicesFg ? SERVICE_TIMEOUT : SERVICE_BACKGROUND_TIMEOUT);
}

可以看到这里通过ActivityManager的Handler创建一个消息，指定类型为ActivityManagerService.SERVICE_TIMEOUT_MSG，并且根据服务是否前后台来设置了不同的Delay值。

接下来我们可以直接去Handler的handleMessage方法中寻找对应的消息是如何处理的。

MainHandler#handleMessage

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
    @Override
    public void handleMessage(Message msg) {
        switch (msg.what) {
        case GC_BACKGROUND_PROCESSES_MSG: {
            synchronized (ActivityManagerService.this) {
                performAppGcsIfAppropriateLocked();
            }
        } break;
        case SERVICE_TIMEOUT_MSG: {
            // 处理后台服务超时消息
            mServices.serviceTimeout((ProcessRecord)msg.obj);
        } break;
        case SERVICE_FOREGROUND_TIMEOUT_MSG: {
            // 处理前台服务超时消息
            mServices.serviceForegroundTimeout((ServiceRecord)msg.obj);
        } break;
         
        ···
          
}

mServices为ActiveServices对象，可以看到这里又交回给ActiveServices来处理。

ActiveServices#serviceTimeout

1
2
3
4
5
6
7
8
9
10
11
void serviceTimeout(ProcessRecord proc) {
    String anrMessage = null;
    
    ···
    
    // 如果Service还在执行且已经超时，并且其所在进程还在执行中，anrMessage不为null
    if (anrMessage != null) {
        // 消费ANR
        proc.appNotResponding(null, null, null, null, false, anrMessage);
    }
}

在这里调用了ProcessRecord的appNotResponding方法来消费ANR事件，执行后续的弹框、dump堆栈等操作。

ProcessRecord#appNotResponding

appNotResponding方法的代码较多，这里我们分为多个部分来进行讲解。

先来看第一部分：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
void appNotResponding(String activityShortComponentName, ApplicationInfo aInfo,
        String parentShortComponentName, WindowProcessController parentProcess,
        boolean aboveSystem, String annotation) {

    ···

    // 几种特殊情况将直接返回
    synchronized (mService) {
        // PowerManager.reboot() can block for a long time, so ignore ANRs while shutting down.
        if (mService.mAtmInternal.isShuttingDown()) {
            Slog.i(TAG, "During shutdown skipping ANR: " + this + " " + annotation);
            return;
        } else if (isNotResponding()) {
            Slog.i(TAG, "Skipping duplicate ANR: " + this + " " + annotation);
            return;
        } else if (isCrashing()) {
            Slog.i(TAG, "Crashing app skipping ANR: " + this + " " + annotation);
            return;
        } else if (killedByAm) {
            Slog.i(TAG, "App already killed by AM skipping ANR: " + this + " " + annotation);
            return;
        } else if (killed) {
            Slog.i(TAG, "Skipping died app ANR: " + this + " " + annotation);
            return;
        }

        // 标记已经处理ANR
        setNotResponding(true);

        // 静默ANR
        if (!isSilentAnr()) {
            ···
        }
    }
}

先是一长串if else，给出了几种比较极端的情况，会直接return，而不会产生一个ANR，这些情况包括：

  • 系统正在重启
  • 进程处于正在关闭的状态
  • 进程处于正在crash的状态
  • 进程处于被kill的状态
  • 相同进程已经处在ANR的流程中

另外很重要的一个逻辑就是判断当前ANR是否是一个SilentAnr，所谓“静默ANR”，其实就是后台ANR，后台ANR跟前台ANR会有不同的表现：前台ANR会弹无响应的Dialog，后台ANR会直接杀死进程。

前后台ANR的判断的原则是：如果发生ANR的进程对用户来说是有感知的，就会被认为是前台ANR，否则是后台ANR。另外，如果在开发者选项中勾选了“显示后台ANR”，那么全部ANR都会被认为是前台ANR。

我们继续分析这个方法：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
if (!isSilentAnr()) {
    int parentPid = pid;
    if (parentProcess != null && parentProcess.getPid() > 0) {
        parentPid = parentProcess.getPid();
    }
  
    // 当前ANR进程的父进程
    if (parentPid != pid) firstPids.add(parentPid);

    // 添加当前进程即system_server进程
    if (MY_PID != pid && MY_PID != parentPid) firstPids.add(MY_PID);

    // 遍历最近使用过的进程列表
    for (int i = getLruProcessList().size() - 1; i >= 0; i--) {
        ProcessRecord r = getLruProcessList().get(i);
        if (r != null && r.thread != null) {
            int myPid = r.pid;
            // 此进程不是当前ANR进程、不是当前ANR进程的父进程、不是system_server进程
            if (myPid > 0 && myPid != pid && myPid != parentPid && myPid != MY_PID) {
                // persistent的进程需要加入firstPids
                if (r.isPersistent()) {
                    firstPids.add(myPid);
                    if (DEBUG_ANR) Slog.i(TAG, "Adding persistent proc: " + r);
                 // treatLikeActivity的进程需要加入firstPids
                } else if (r.treatLikeActivity) {
                    firstPids.add(myPid);
                    if (DEBUG_ANR) Slog.i(TAG, "Adding likely IME: " + r);
                } else {
                    // 其余的加入lastPids
                    lastPids.put(myPid, Boolean.TRUE);
                    if (DEBUG_ANR) Slog.i(TAG, "Adding ANR proc: " + r);
                }
            }
        }
    }
}

···

 // 添加native进程
String[] nativeProcs = null;
if (isSilentAnr()) {
     for (int i = 0; i < NATIVE_STACKS_OF_INTEREST.length; i++) {
        if (NATIVE_STACKS_OF_INTEREST[i].equals(processName)) {
            nativeProcs = new String[] { processName };
            break;
        }
    }
} else {
    nativeProcs = NATIVE_STACKS_OF_INTEREST;
}

int[] pids = nativeProcs == null ? null : Process.getPidsForCommands(nativeProcs);
ArrayList<Integer> nativePids = null;

if (pids != null) {
    nativePids = new ArrayList<>(pids.length);
    for (int i : pids) {
        nativePids.add(i);
    }
}

发生ANR后，为了能让开发者知道ANR的原因，方便定位问题，会dump很多信息到ANR Trace文件里，上面的逻辑就是选择需要dump的进程。

ANR Trace文件是包含许多进程的Trace信息的，因为产生ANR的原因有可能是其他的进程抢占了太多资源，或者IPC到其他进程（尤其是系统进程）的时候卡住导致的。

需要被dump的进程被分为了firstPids、nativePids以及extraPids三类：

  • firstPIds：firstPids是需要首先dump的重要进程，发生ANR的进程无论如何是一定要被dump的，也是首先被dump的，所以第一个被加到firstPids中。如果是SilentAnr（即后台ANR），不用再加入任何其他的进程。如果不是，需要进一步添加其他的进程：
    • 如果发生ANR的进程不是system_server进程的话，需要添加system_server进程
    • 接下来轮询AMS维护的一个LRU的进程List，如果最近访问的进程包含了persistent的进程，或者带有BIND_TREAT_LIKE_ACTVITY标签的进程，都添加到firstPids中
  • LRU进程List中的其他进程，都会首先添加到lastPids中，然后lastPids会进一步被选出最近CPU使用率高的进程，进一步组成extraPids
  • nativePids最为简单，是一些固定的native的系统进程，定义在WatchDog.java中

拿到需要dump的所有进程的pid后，AMS开始按照firstPids、nativePids、extraPids的顺序dump这些进程的堆栈：

1
2
3
4
5
// For background ANRs, don't pass the ProcessCpuTracker to
// avoid spending 1/2 second collecting stats to rank lastPids.
File tracesFile = ActivityManagerService.dumpStackTraces(firstPids,
        (isSilentAnr()) ? null : processCpuTracker, (isSilentAnr()) ? null : lastPids,
        nativePids);

这个方法是我们需要重点关注的，接下来跟进到AMS里。

ActivityManagerService#dumpStackTraces

frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
public static File dumpStackTraces(ArrayList<Integer> firstPids,
        ProcessCpuTracker processCpuTracker, SparseArray<Boolean> lastPids,
        ArrayList<Integer> nativePids) {
    ArrayList<Integer> extraPids = null;

    ···

    // String ANR_TRACE_DIR = "/data/anr";
    final File tracesDir = new File(ANR_TRACE_DIR);
    
    // 默认只保存64个anr日志文件，删除多余的
    maybePruneOldTraces(tracesDir);

    // 根据时间来创建ANR dump文件
    File tracesFile = createAnrDumpFile(tracesDir);
    if (tracesFile == null) {
        return null;
    }

    dumpStackTraces(tracesFile.getAbsolutePath(), firstPids, nativePids, extraPids);
    return tracesFile;
}

这里创建了日志文件，可以看到目录为/data/anr，然后继续调用了重载方法dumpStackTraces。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
public static void dumpStackTraces(String tracesFile, ArrayList<Integer> firstPids,
        ArrayList<Integer> nativePids, ArrayList<Integer> extraPids) {


    long remainingTime = 20 * 1000;

   
    if (firstPids != null) {
        int num = firstPids.size();
        for (int i = 0; i < num; i++) {
            final long timeTaken = dumpJavaTracesTombstoned(firstPids.get(i), tracesFile,
                                                            remainingTime);

            remainingTime -= timeTaken;
            if (remainingTime <= 0) {
                Slog.e(TAG, "Aborting stack trace dump (current firstPid=" + firstPids.get(i) +
                       "); deadline exceeded.");
                return;
            }

            if (DEBUG_ANR) {
                Slog.d(TAG, "Done with pid " + firstPids.get(i) + " in " + timeTaken + "ms");
            }
        }
    }
  
    ···
      
}

首先关注到remainingTime变量，这个变量规定了我们dump所有进程的最长时间，因为dump进程所有线程的堆栈本身就是一个重操作，何况是要dump许多进程，所以规定了发生ANR之后，dump全部进程的总时间不能超过20秒。如果超过了，马上返回，确保ANR弹窗可以及时的弹出（或者被kill掉）。

继续跟进到dumpJavaTracesTombstoned方法：

1
2
3
4
5
6
7
8
9
private static long dumpJavaTracesTombstoned(int pid, String fileName, long timeoutMs) {
    final long timeStart = SystemClock.elapsedRealtime();
    boolean javaSuccess = Debug.dumpJavaBacktraceToFileTimeout(pid, fileName,
            (int) (timeoutMs / 1000));
  
    ···
      
    return SystemClock.elapsedRealtime() - timeStart;
}

方法中使用dumpJavaBacktraceToFileTimeout方法来完成Java堆栈的dump操作。

关于具体的dump操作需要追踪到native层，一路跟踪到debuggerd_client.cpp文件中的debuggerd_trigger_dump方法。

debuggerd_trigger_dump

system/core/debuggerd/client/debuggerd_client.cpp

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
bool debuggerd_trigger_dump(pid_t tid, DebuggerdDumpType dump_type, unsigned int timeout_ms,
                            unique_fd output_fd) {
  pid_t pid = tid;
  
  ···

  // Send the signal.
  const int signal = (dump_type == kDebuggerdJavaBacktrace) ? SIGQUIT : BIONIC_SIGNAL_DEBUGGER;
  sigval val = {.sival_int = (dump_type == kDebuggerdNativeBacktrace) ? 1 : 0};
  if (sigqueue(pid, signal, val) != 0) {
    log_error(output_fd, errno, "failed to send signal to pid %d", pid);
    return false;
  }
  
  ···

  LOG(INFO) << TAG "done dumping process " << pid;

  return true;
}

这里会通过sigqueue向需要dump堆栈的进程发送SIGQUIT信号，也就是signal 3信号，而发生ANR的进程，也就是我们的APP进程同样也会通过这个信号来开启进程的堆栈dump过程。

每一个应用进程都会有一个SignalCatcher线程，专门处理SIGQUIT，源码位于art/runtime/signal_catcher.cc文件中。

SignalCatcher#Run

art/runtime/signal_catcher.cc

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
void* SignalCatcher::Run(void* arg) {
  SignalCatcher* signal_catcher = reinterpret_cast<SignalCatcher*>(arg);
  
  ···
    
  Thread* self = Thread::Current();
  
  ···

  // Set up mask with signals we want to handle.
  SignalSet signals;
  signals.Add(SIGQUIT);
  signals.Add(SIGUSR1);

  while (true) {
    // 可能阻塞
    int signal_number = signal_catcher->WaitForSignal(self, signals);
    if (signal_catcher->ShouldHalt()) {
      runtime->DetachCurrentThread();
      return nullptr;
    }

    switch (signal_number) {
    case SIGQUIT:
      signal_catcher->HandleSigQuit();
      break;
    case SIGUSR1:
      signal_catcher->HandleSigUsr1();
      break;
    default:
      LOG(ERROR) << "Unexpected signal %d" << signal_number;
      break;
    }
  }
}

SignalCatcher中开启了一个死循环，其中调用了WaitForSignal方法来阻塞地等待信号到达，主要关注两个信号：SIGQUIT和SIGUSR1。当SignalCatcher接收到SIGQUIT信号时，就会调用HandleSigQuit方法。

SignalCatcher#HandleSigQuit

1
2
3
4
5
6
7
8
9
10
void SignalCatcher::HandleSigQuit() {
  
  ···

  runtime->DumpForSigQuit(os);

  ···
    
  Output(os.str());
}

调用了Runtime中的DumpForSigQuit方法。

Runtime#DumpForSigQuit

art/runtime/runtime.cc

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
void Runtime::DumpForSigQuit(std::ostream& os) {
  GetClassLinker()->DumpForSigQuit(os);
  GetInternTable()->DumpForSigQuit(os);
  GetJavaVM()->DumpForSigQuit(os);
  GetHeap()->DumpForSigQuit(os);
  oat_file_manager_->DumpForSigQuit(os);
  if (GetJit() != nullptr) {
    GetJit()->DumpForSigQuit(os);
  } else {
    os << "Running non JIT\n";
  }
  DumpDeoptimizations(os);
  TrackedAllocators::Dump(os);
  GetMetrics()->DumpForSigQuit(os);
  os << "\n";

  thread_list_->DumpForSigQuit(os);
  BaseMutex::DumpAll(os);

  // Inform anyone else who is interested in SigQuit.
  {
    ScopedObjectAccess soa(Thread::Current());
    callbacks_->SigQuit();
  }
}

可以看到这里才真正完成了我们应用App所在进程的dump工作。

因此我们可以得出一条重要结论：发生ANR的进程在接收到系统进程发送过来的SIGQUIT信号时，会开启自身的堆栈dump过程。

这一结论对我们监控ANR有重要意义，后文会详细分析如何进行监控。

重新回到appNotResponding方法中来看后续操作。

此时我们已经完成了所有相关进程的dump过程，并且拿到了保存的文件File对象，后续还需要输出log、弹出ANR弹窗。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
void appNotResponding(String activityShortComponentName, ApplicationInfo aInfo,
        String parentShortComponentName, WindowProcessController parentProcess,
        boolean aboveSystem, String annotation) {
  
   ···

    Slog.e(TAG, info.toString());
    if (tracesFile == null) {
        // 没有抓到traces，重新给进程发送SIGNAL_QUIT信号
        Process.sendSignal(pid, Process.SIGNAL_QUIT);
    }

    StatsLog.write(StatsLog.ANR_OCCURRED, uid, processName,
            activityShortComponentName == null ? "unknown": activityShortComponentName,
            annotation,
            (this.info != null) ? (this.info.isInstantApp()
                    ? StatsLog.ANROCCURRED__IS_INSTANT_APP__TRUE
                    : StatsLog.ANROCCURRED__IS_INSTANT_APP__FALSE)
                    : StatsLog.ANROCCURRED__IS_INSTANT_APP__UNAVAILABLE,
            isInterestingToUserLocked()
                    ? StatsLog.ANROCCURRED__FOREGROUND_STATE__FOREGROUND
                    : StatsLog.ANROCCURRED__FOREGROUND_STATE__BACKGROUND,
            getProcessClassEnum(),
            (this.info != null) ? this.info.packageName : "");
    final ProcessRecord parentPr = parentProcess != null
            ? (ProcessRecord) parentProcess.mOwner : null;
  
    // 输出log到dropBox
    mService.addErrorToDropBox("anr", this, processName, activityShortComponentName,
            parentShortComponentName, parentPr, annotation, cpuInfo, tracesFile, null);

    if (mWindowProcessController.appNotResponding(info.toString(), () -> kill("anr", true),
            () -> {
                synchronized (mService) {
                    mService.mServices.scheduleServiceTimeoutLocked(this);
                }
            })) {
        return;
    }

    synchronized (mService) {

        if (mService.mBatteryStatsService != null) {
            mService.mBatteryStatsService.noteProcessAnr(processName, uid);
        }

        // 如果是后台anr 直接杀死进程
        if (isSilentAnr() && !isDebugging()) {
            kill("bg anr", true);
            return;
        }

        // 错误报告
        makeAppNotRespondingLocked(activityShortComponentName,
                annotation != null ? "ANR " + annotation : "ANR", info.toString());

        if (mService.mUiHandler != null) {
          
            // 发送SHOW_NOT_RESPONDING_UI_MSG，弹出Anr dialog
            Message msg = Message.obtain();
            msg.what = ActivityManagerService.SHOW_NOT_RESPONDING_UI_MSG;
            msg.obj = new AppNotRespondingDialog.Data(this, aInfo, aboveSystem);

            mService.mUiHandler.sendMessage(msg);
        }
    }
}

可以看到在完成dump之后主要做了以下操作：

  1. 输出日志到logcat
  2. 如果没有获取到tracesFile，再次给进程发送一个SIGNAL_QUIT信号
  3. 输出日志到DropBox
  4. 如果是后台ANR，直接杀进程
  5. 发送消息弹出ANR Dialog

到这里整个触发流程就结束了，下面来看看对于没有达到触发ANR边界的消息，是如何移除的。

消息移除

我们可以通过全局搜索的方式来寻找ANR消息类型的remove是在何时调用的：

消息移除搜索

可以看到是在ActiveServices中的serviceDoneExecutingLocked进行消息的移除。

继续利用全局搜索我们可以知道最早的调用时机是在Service的Create生命周期中，具体是在ActivityThread的handleCreateService方法中，接着来看这个方法。

ActivityThread#handleCreateService

frameworks/base/core/java/android/app/ActivityThread.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
private void handleCreateService(CreateServiceData data) {
    ···
    try {
        ···
        try {
            // 移除超时消息
            ActivityManager.getService().serviceDoneExecuting(
                    data.token, SERVICE_DONE_EXECUTING_ANON, 0, 0);
        } catch (RemoteException e) {
            throw e.rethrowFromSystemServer();
        }
    } catch (Exception e) {
        if (!mInstrumentation.onException(service, e)) {
            throw new RuntimeException(
                "Unable to create service " + data.info.name
                + ": " + e.toString(), e);
        }
    }
}

在handleCreateService中通过IPC的方式来通知AMS移除对应的消息。

另外在Service的其他生命周期中也有调用serviceDoneExecuting方法，这里不再赘述。

ANR日志的分析

上节我们知道ANR产生时会进行堆栈dump，并把日志文件输出到/data/anr/traces.txt文件中，我们可以尝试手写一个ANR来分析其日志。

模拟死锁导致ANR

利用synchronized可以很容易写出死锁代码：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
private val lock1 = Object()
private val lock2 = Object()

private fun tryDeadLock() {
    thread {
        // 子线程持有锁1
        synchronized(lock1) {
            try {
                Thread.sleep(100L)
            } catch (e: Exception) {
                e.printStackTrace()
            }

            // 竞争锁2
            synchronized(lock2) {

            }
        }
    }

    // 主线程持有锁2
    synchronized(lock2) {
        try {
            Thread.sleep(100L)
        } catch (e: Exception) {
            e.printStackTrace()
        }

        // 竞争锁1
        synchronized(lock1) {
        }
    }
}

然后提供一个按钮来触发ANR，界面如下所示：


点击Button会调用tryDeadLock方法，为了触发ANR效果，我们需要再点击一下屏幕发送一些触摸事件，过一会就会看到ANR 弹窗了。


分析日志

产生ANR之后可以使用Device File Explorer看到/data/anr目录下出现了一个日志文件了，可以直接打开也可以使用adb pull命令从手机传到电脑中，需要注意的是如果使用的是Google Play版的镜像创建的模拟器是没有权限访问这个目录的，文件如下：

ANR日志文件

由于参与dump的进程和线程很多，因此这个文件里面的日志可能会非常多，善用搜索可以找到关键信息。

首先搜索main，来看主线程：

主线程dump日志

可以看到第一行就清晰的指出了当前主线程状态为”blocked“，也就是阻塞状态。

下面的堆栈信息告诉我们，MainActivity的tryDeadLock方法中主线程在等待一个lock<0x0475d18b>释放，这个lock被id为2的线程持有，并且主线程持有一个Object类型的锁，地址为<0x0dc0eb5a>。

那么我们可以搜索tid=2的线程查看其堆栈情况：
tid为2线程dump日志

可以看到这个tid为2的线程同样处于阻塞状态，并且日志告诉我们它也在等待一个锁<0x0dc0eb5a>释放，而这个锁则被id为1的线程持有，同时它持有锁<0x0475d18b>。

id为1的线程实际上就是我们的主线程main。到这里我们发现线程2与主线程互相持有对方需要的锁，并且同时又在请求对方线程持有的锁，造成了循环等待，产生死锁。通过ANR日志，可以很清楚分析出这个ANR是死锁导致的，并且有具体堆栈信息。

上面只是举例一种非常简单的ANR情况，实际项目中可能会有很多意料之外的ANR，而且可能会涉及到多个进程例如system_server，那么对于线上项目，要如何拿到这个ANR日志文件呢？下面就来讨论一下微信的ANR监控方案。

微信ANR监控方案

微信Android客户端的ANR监控方案

参考

  1. 微信Android客户端的ANR监控方案
  2. 卡顿、ANR、死锁，线上如何监控？
  3. 理解Android ANR的触发原理