【Android 系统开发】_“性能优化”篇 -- ANR 之 Service 超时

81951932 2019-07-01

1. 核心源码

关键类路径(/frameworks/base/)
ActiveServices.javaservices/core/java/com/android/server/am/ActiveServices.java
ActivityManagerService.javaservices/core/java/com/android/server/am/ActivityManagerService.java
AppErrors.javaservices/core/java/com/android/server/am/AppErrors.java

2. ANR 基础认知

2.1 ANR 是什么?

ANR(Application Not Responding),应用程序无响应,简单一个定义,却涵盖了很多 Android 系统的设计思想。

首先,ANR 属于应用程序的范畴,这不同于 SNR(System Not Respoding),SNR 反映的问题是系统进程(system_server)失去了响应能力,而 ANR 明确将问题圈定在应用程序。SNR 由 Watchdog 机制保证,ANR 由消息处理机制保证,Android 在系统层实现了一套精密的机制来发现 ANR,核心原理是消息调度超时处理

其次,ANR 机制主体实现在系统层。所有与 ANR 相关的消息,都会经过系统进程(system_server)调度,然后派发到应用进程完成对消息的实际处理,同时,系统进程设计了不同的超时限制来跟踪消息的处理。一旦应用程序处理消息不当,超时限制就起作用了,它收集一些系统状态,例如:CPU/IO使用情况、进程函数调用栈,并且报告用户有进程无响应了(ANR 对话框)

然后,ANR 问题本质是一个性能问题。ANR 机制实际上对应用程序主线程的限制,要求主线程在限定的时间内处理完一些最常见的操作(启动服务、处理广播、处理输入),如果处理超时,则认为主线程已经失去了响应其他操作的能力。主线程中的耗时操作,例如:密集CPU运算、大量IO、复杂界面布局等,都会降低应用程序的响应能力。

最后,部分 ANR 问题是很难分析的,有时候由于系统底层的一些影响,导致消息调度失败,出现问题的场景又难以复现。这类 ANR 问题往往需要花费大量的时间去了解系统的一些行为,超出了 ANR 机制本身的范畴。

2.2 ANR 机制

分析一些初级的 ANR 问题,只需要简单理解最终输出的日志即可,但对于一些由系统问题(例如:CPU 负载过高、进程卡死)引发的 ANR,就需要对整个 ANR 机制有所了解,才能定位出问题的原因。

ANR 机制可以分为两部分:

      ✎  ANR 的监测:Android 对于不同的 ANR 类型(Broadcast,Service,InputEvent)都有一套监测机制。

      ✎  ANR 的报告:在监测到 ANR 以后,需要显示 ANR 对话框、输出日志(发生 ANR 时的进程函数调用栈、CPU 使用情况等)。

2.3 ANR 的触发原因

前面我们说过,出现 ANR 之后一个直观现象就是系统会展示出一个 ANR 对话框。

谷歌文档中对 ANR 产生的原因是这么描述的:

Android 系统中的应用被 ActivityManagerServiceWindowManagerService 两个系统服务监控着,系统会在如下两种情况展示出 ANR 的对话框!

      ✎  KeyDispatchTimeout ( 5 seconds ) :按键或触摸事件在特定时间内无响应
      ✎  BroadcastTimeout ( 10 seconds ):BroadcastReceiver 在特定时间内无法处理完成
      ✎  ServiceTimeout ( 20 seconds ) :Service 在特定的时间内无法处理完成

3. Service 超时监测机制

Service 运行在应用程序的主线程,如果 Service 的执行时间超过 20 秒,则会引发 ANR。

当发生 Service ANR 时,一般可以先排查一下在 Service 的生命周期函数中有没有做耗时的操作,例如复杂的运算、IO 操作等。如果应用程序的代码逻辑查不出问题,就需要深入检查当前系统的状态:CPU 的使用情况、系统服务的状态等,判断当时发生 ANR 进程是否受到系统运行异常的影响。

那么,系统是如何检测 Service 超时的呢?Android 是通过设置定时消息实现的。定时消息是由 AMS 的消息队列处理的,AMS 有 Service 运行的上下文信息,所以在 AMS 中设置一套超时检测机制也是合情合理的。

Service ANR 机制相对最为简单,主体实现在ActiveServices中。

在 Service 的启动流程中,Service 进程 attach 到 system_server 进程后会调用 realStartServiceLocked() 方法。

3.1 realStartServiceLocked

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

public final class ActiveServices {

    private final void realStartServiceLocked(ServiceRecord r,
            ProcessRecord app, boolean execInFg) throws RemoteException {

        // 发送 delay 消息(SERVICE_TIMEOUT_MSG)
        bumpServiceExecutingLocked(r, execInFg, "create");

        boolean created = false;
        try {
            
            // 最终执行服务的 onCreate() 方法
            app.thread.scheduleCreateService(r, r.serviceInfo, mAm.
                compatibilityInfoForPackageLocked(r.serviceInfo.applicationInfo),
                app.repProcState);

            ... ...
        }
    }
    
}

3.2 bumpServiceExecutingLocked

private final void bumpServiceExecutingLocked(...) {

    scheduleServiceTimeoutLocked(r.app);
    
}

3.3 scheduleServiceTimeoutLocked

void scheduleServiceTimeoutLocked(ProcessRecord proc) {
    if (proc.executingServices.size() == 0 || proc.thread == null) {
        return;
    }
    Message msg = mAm.mHandler.obtainMessage(
            ActivityManagerService.SERVICE_TIMEOUT_MSG);
    msg.obj = proc;
    // 当超时后仍没有 remove 该 SERVICE_TIMEOUT_MSG 消息,
    // 通过 AMS.MainHandler 抛出一个定时消息。
    mAm.mHandler.sendMessageDelayed(msg,
            proc.execServicesFg ? SERVICE_TIMEOUT : SERVICE_BACKGROUND_TIMEOUT);
}

上述方法通过 AMS.MainHandler 抛出一个定时消息 SERVICE_TIMEOUT_MSG

3.4 serviceDoneExecutingLocked

前台进程中执行 Service,超时时间是 SERVICE_TIMEOUT(20 秒)

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

后台进程中执行 Service,超时时间是 SERVICE_BACKGROUND_TIMEOUT(200 秒)

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

当 Service 的生命周期结束时(不会 ANR),会调用 serviceDoneExecutingLocked() 方法,之前抛出的 SERVICE_TIMEOUT_MSG 消息在这个方法中会被清除。

void serviceDoneExecutingLocked(ServiceRecord r, int type, int startId, int res) {
    boolean inDestroying = mDestroyingServices.contains(r);
    if (r != null) {
        ... ...        
        serviceDoneExecutingLocked(r, inDestroying, inDestroying);
    }
}

private void serviceDoneExecutingLocked(ServiceRecord r, boolean inDestroying,
          boolean finishing) {    
    ... ...
    if (r.executeNesting <= 0) {
        if (r.app != null) {    
            ... ...
            // 当前服务所在进程中没有正在执行的service,清除 SERVICE_TIMEOUT_MSG 消息
            if (r.app.executingServices.size() == 0) {
                mAm.mHandler.removeMessages(
                             ActivityManagerService.SERVICE_TIMEOUT_MSG, r.app);            
                ... ...
            }
    ... ...
}

3.5 handleMessage

如果没有 Remove 掉 SERVICE_TIMEOUT_MSG 呢?接下来我们看看对于 ANR 的处理逻辑。

在 system_server 进程中有一个 Handler 线程,名叫 ActivityManager

如果在超时时间内,SERVICE_TIMEOUT_MSG 没有被清除,便会向该 Handler 线程发送一条信息 SERVICE_TIMEOUT_MSG

final class MainHandler extends Handler {
    ... ...

    @Override
    public void handleMessage(Message msg) {
        switch (msg.what) {
            ... ...
            
            case SERVICE_TIMEOUT_MSG: {
                mServices.serviceTimeout((ProcessRecord)msg.obj);
            } break;
        ... ...
    }
}

3.6 serviceTimeout

void serviceTimeout(ProcessRecord proc) {
    String anrMessage = null;

    synchronized(mAm) {
        ... ...
        
        long nextTime = 0;

        // 寻找运行超时的 Service
        for (int i = proc.executingServices.size() - 1; i >= 0; i--) {
            ServiceRecord sr = proc.executingServices.valueAt(i);
            if (sr.executingStart < maxTime) {
                timeout = sr;
                break;
            }
            if (sr.executingStart > nextTime) {
                nextTime = sr.executingStart;
            }
        }

        // 判断执行 Service 超时的进程是否在最近运行进程列表,如果不在,则忽略这个 ANR
        if (timeout != null && mAm.mLruProcesses.contains(proc)) {
            Slog.w(TAG, "Timeout executing service: " + timeout);
            StringWriter sw = new StringWriter();
            PrintWriter pw = new FastPrintWriter(sw, false, 1024);
            pw.println(timeout);
            timeout.dump(pw, "    ");
            pw.close();
            mLastAnrDump = sw.toString();
            mAm.mHandler.removeCallbacks(mLastAnrDumpClearer);
            mAm.mHandler.postDelayed(mLastAnrDumpClearer, 
                                           LAST_ANR_LIFETIME_DURATION_MSECS);
            anrMessage = "executing service " + timeout.shortName;
        ... ...
    }

    if (anrMessage != null) {
        // 当存在 timeout 的 service,则执行 appNotResponding
        mAm.mAppErrors.appNotResponding(proc, null, null, false, anrMessage);
    }
}

上述方法会找到当前进程已经超时的 Service,经过一些判定后,决定要报告 ANR,最终调用 AMS.appNotResponding() 方法。

走到这一步,ANR 机制已经完成了监测报告任务,剩下的任务就是 ANR 结果的输出,我们称之为 ANR 的报告机制。ANR 的报告机制是通过 AMS.appNotResponding() 完成的,Broadcast 和 InputEvent 类型的 ANR 最终也都会调用这个方法。

4. ANR 信息收集过程

接下来我们看看 Android ANR 的信息收集过程!

4.1 appNotResponding

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

class AppErrors {

    final void appNotResponding(ProcessRecord app, ActivityRecord activity,
            ActivityRecord parent, boolean aboveSystem, final String annotation) {
        ... ...

        long anrTime = SystemClock.uptimeMillis();
        if (ActivityManagerService.MONITOR_CPU_USAGE) {
            mService.updateCpuStatsNow();   // 更新 cpu 统计信息
        }

        boolean showBackground = Settings.Secure.
                getInt(mContext.getContentResolver(),
                           Settings.Secure.ANR_SHOW_BACKGROUND, 0) != 0;

        boolean isSilentANR;

        synchronized (mService) {
            if (mService.mShuttingDown) {
                return;
            } else if (app.notResponding) {
                return;
            } else if (app.crashing) {
                return;
            } else if (app.killedByAm) {
                return;
            } else if (app.killed) {
                return;
            }

            // In case we come through here for the same app before completing
            // this one, mark as anring now so we will bail out.
            app.notResponding = true;

            // 记录 ANR 到 EventLog
            EventLog.writeEvent(EventLogTags.AM_ANR, app.userId, app.pid,
                    app.processName, app.info.flags, annotation);

            // 将当前进程添加到 firstPids
            firstPids.add(app.pid);

            // Don't dump other PIDs if it's a background ANR
            isSilentANR = !showBackground 
                                  && !isInterestingForBackgroundTraces(app);
            if (!isSilentANR) {
                int parentPid = app.pid;
                if (parent != null && parent.app != null && parent.app.pid > 0) {
                    parentPid = parent.app.pid;
                }
                if (parentPid != app.pid) firstPids.add(parentPid);

                // 将 system_server 进程添加到 firstPids
                if (MY_PID != app.pid 
                                && MY_PID != parentPid) firstPids.add(MY_PID);

                for (int i = mService.mLruProcesses.size() - 1; i >= 0; i--) {
                    ProcessRecord r = mService.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) {
                                // 将 persistent 进程添加到 firstPids
                                firstPids.add(pid);
                            } else if (r.treatLikeActivity) {
                                firstPids.add(pid);
                            } else {
                                // 其他进程添加到 lastPids
                                lastPids.put(pid, Boolean.TRUE);
                            }
                        }
                    }
                }
            }
        }

        // 记录 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 对象 
        ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(true);

        ... ...

        // 输出 traces 信息
        File tracesFile = ActivityManagerService.dumpStackTraces(
                true, firstPids,
                (isSilentANR) ? null : processCpuTracker,
                (isSilentANR) ? null : lastPids,
                nativePids);

        String cpuInfo = null;
        if (ActivityManagerService.MONITOR_CPU_USAGE) {
            mService.updateCpuStatsNow();
            synchronized (mService.mProcessCpuTracker) {
                cpuInfo = mService.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());
        if (tracesFile == null) {
            Process.sendSignal(app.pid, Process.SIGNAL_QUIT);
        }
        ... ...
                        
        // 将 traces 文件和 CPU 使用率信息保存到 dropbox,即 data/system/dropbox 目录
        mService.addErrorToDropBox("anr", app, app.processName,
                          activity, parent, annotation, cpuInfo, tracesFile, null);
        ... ...

        synchronized (mService) {
            mService.mBatteryStatsService.noteProcessAnr(app.processName, app.uid);

            // 后台 ANR 的情况, 直接杀掉
            if (isSilentANR) {
                app.kill("bg anr", true);
                return;
            }

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

            // 弹出 ANR 对话框
            Message msg = Message.obtain();
            msg.what = ActivityManagerService.SHOW_NOT_RESPONDING_UI_MSG;
            msg.obj = new AppNotRespondingDialog.Data(app, activity, aboveSystem);

            // 向 ui 线程发送,内容为 SHOW_NOT_RESPONDING_MSG 的消息
            mService.mUiHandler.sendMessage(msg);
        }
    }
    
}
当发生 ANR 时, 会按顺序依次执行:

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

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

       ✒ 1、firstPids 队列:第一个是 ANR 进程,第二个是 system_server,剩余是所有 persistent 进程;
       ✒ 2、Native 队列:是指 /system/bin/ 目录的 mediaserversdcard 以及 surfaceflinger 进程;
       ✒ 3、lastPids 队列: 是指 mLruProcesses 中的不属于 firstPids 的所有进程。

4.2 dumpStackTraces

继续看看 dump 出 trace 信息的流程:

// ActivityManagerService.java

    public static File dumpStackTraces(boolean clearTraces, ... ,nativePids) {
        ... ...

        if (tracesDirProp.isEmpty()) {
            // 默认为 data/anr/traces.txt
            String globalTracesPath = 
                          SystemProperties.get("dalvik.vm.stack-trace-file", null);

            tracesFile = new File(globalTracesPath);
            try {
                if (clearTraces && tracesFile.exists()) {
                    tracesFile.delete();      // 删除已存在的 traces 文件
                }

                // 这里会保证 data/anr/traces.txt 文件内容是全新的方式,而非追加
                tracesFile.createNewFile();   // 创建 traces 文件
                FileUtils.setPermissions(globalTracesPath, 0666, -1, -1);
            } catch (IOException e) {
                Slog.w(TAG, "Unable to prepare ANR traces file: " + tracesFile, e);
                return null;
            }
        } else {
        }

        // 输出 trace 内容
        dumpStackTraces(tracesFile.getAbsolutePath(), firstPids, nativePids,
                                         extraPids, useTombstonedForJavaTraces);
        return tracesFile;
    }

4.3 dumpStackTraces

// ActivityManagerService.java

    private static void dumpStackTraces(String tracesFile, ...) {

        final DumpStackFileObserver observer;
        if (useTombstonedForJavaTraces) {
            observer = null;
        } else {
            observer = new DumpStackFileObserver(tracesFile);
        }

        // We must complete all stack dumps within 20 seconds.
        long remainingTime = 20 * 1000;
        try {
            if (observer != null) {
                observer.startWatching();
            }

            // 首先,获取 firstPids 进程的 stacks
            if (firstPids != null) {
                int num = firstPids.size();
                for (int i = 0; i < num; i++) {
                    final long timeTaken;
                    if (useTombstonedForJavaTraces) {
                        timeTaken = dumpJavaTracesTombstoned(firstPids.get(i),
                                                   tracesFile, remainingTime);
                    } else {
                        timeTaken = observer.dumpWithTimeout(firstPids.get(i),
                                                               remainingTime);
                    }
                    ... ...    
                }
            }

            // 下一步,获取 native 进程的 stacks
            if (nativePids != null) {
                for (int pid : nativePids) {
                    ... ...
                    
                    // 输出 native 进程的 trace
                    Debug.dumpNativeBacktraceToFileTimeout(
                            pid, tracesFile, (int) (nativeDumpTimeoutMs / 1000));
                            
                    final long timeTaken = SystemClock.elapsedRealtime() - start;
                    ... ...
                }
            }

            // Lastly, dump stacks for all extra PIDs from the CPU tracker.
            if (extraPids != null) {
                ... ...
                }
            }
        } finally {
            if (observer != null) {
                observer.stopWatching();
            }
        }
    }

4.4 小结

触发 ANR 时系统会输出关键信息:

       ✒ 1、将 am_anr 信息,输出到 EventLog
       ✒ 2、获取重要进程 trace 信息,保存到 /data/anr/traces.txt
       ✒ 3、ANR Reason 以及 CPU 使用情况信息,输出到 main log;
       ✒ 4、再将 CPU使用情况 和进程 trace 文件信息,再保存到 /data/system/dropbox

5. 总结

当 Service 出现 ANR 时,最终调用到 AMS.appNotResponding()方法。

       ✒ 1、对于前台服务,则超时为 SERVICE_TIMEOUT = 20s

       ✒ 2、对于后台服务,则超时为 SERVICE_BACKGROUND_TIMEOUT = 200s

       ✒ 3、Service 超时检测机制:超过一定时间没有执行完相应操作来触发延时消息,则会触发 ANR;

相关推荐