Android性能优化（七）之你真的理解ANR吗？

作者: 未来的理想 | 来源:发表于2017-04-06 20:01 被阅读1659次

1、前言

在上一篇文章《Android性能优化（六）之卡顿那些事》中，我们提到了卡顿的成因、检测卡顿的途径以及避免卡顿的方法。卡顿再扩大就会产生大名鼎鼎的ANR（Application Not Responding），然后告诉用户你的App无响应，继续等待或者强制关闭，很大的概率用户可能会顺手卸载如此卡的App。

ANR造成的影响特别严重，而在实际开发过程中我们一般都会使用异步来规避ANR，但同时也正因为此我们可能会对ANR熟视无睹：因为常见，所以多见不怪！不信我来提个问题：

在《Multidex（二）之 Dex 预加载优化》中采用单独开进程执行Dex预加载优化的操作时，主进程在后台sleep()，为什么不会出现ANR呢？

2、 ANR分析

2.1 ANR的分类：

KeyDispatchTimeout –按键或触摸事件在特定时间内无响应；
BroadcastTimeout –BroadcastReceiver在特定时间内无法处理完成；
ServiceTimeout –Service在特定的时间内无法处理完成；

2.2 ANR的发生原因：

应用自身引起，例如：
- 主线程阻塞、IOWait等；
其他进程间接引起，例如：
- 当前应用进程进行进程间通信请求其他进程，其他进程的操作长时间没有反馈；
- 其他进程的CPU占用率高，使得当前应用进程无法抢占到CPU时间片；

2.3 ANR日志分析：

当发生ANR的时候Logcat中会出现提示；

04-06 15:58:46.215 23480-23483/com.example.testanr I/art: Thread[2,tid=23483,WaitingInMainSignalCatcherLoop,Thread*=0x7fa2307000,peer=0x12cb40a0,"Signal Catcher"]: reacting to signal 3
04-06 15:58:46.364 23480-23483/com.example.testanr I/art: Wrote stack traces to '/data/anr/traces.txt'

ANR的Log信息保存在：/data/anr/traces.txt，每一次新的ANR发生，会把之前的ANR信息覆盖掉。

例如：

04-01 13:12:11.572 I/InputDispatcher( 220): Application is not responding:Window{2b263310com.android.email/com.android.email.activity.SplitScreenActivitypaused=false}.
5009.8ms since event, 5009.5ms since waitstarted
04-0113:12:11.572 I/WindowManager( 220): Input event 
dispatching timedout sending 
tocom.android.email/com.android.email.activity.SplitScreenActivity

04-01 13:12:14.123 I/Process( 220): Sending signal. PID: 21404 SIG:3---发生ANR的时间和生成trace.txt的时间
04-01 13:12:14.123 I/dalvikvm(21404):threadid=4: reacting to signal 3 ……
04-0113:12:15.872 E/ActivityManager( 220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity)
04-0113:12:15.872 E/ActivityManager( 220): Reason:keyDispatchingTimedOut  -----ANR的类型
04-0113:12:15.872 E/ActivityManager( 220): Load: 8.68 / 8.37 / 8.53 --CPU的负载情况
04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 4361ms to 699ms ago ----CPU在ANR发生前的使用情况；备注：这个ago，是发生前一段时间的使用情况，不是当前时间点的使用情况；

04-0113:12:15.872 E/ActivityManager( 220): 5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults:
10 minor
04-0113:12:15.872 E/ActivityManager( 220): 4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11
minor 2 major
04-0113:12:15.872 E/ActivityManager( 220): 0.9%52/spi_qsd.0: 0% user + 0.9% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%296/com.android.systemui: 0.5% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait----注意这行：注意87%的iowait
04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 3697ms to 4223ms later:-- ANR后CPU的使用量
04-0113:12:15.872 E/ActivityManager( 220): 25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor
04-0113:12:15.872 E/ActivityManager( 220): 16% 21603/__eas(par.hakan: 16% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 7.2% 21406/GC: 7.2% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 1.8% 21409/Compiler: 1.8% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor
04-0113:12:15.872 E/ActivityManager( 220): 5.5% 263/InputDispatcher: 0% user + 5.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 32%TOTAL: 28% user + 3.7% kernel

从Logcat中可以得到以下信息：

导致ANR的包名（com.android.emai），类名（com.android.email.activity.SplitScreenActivity），进程PID（21404）
导致ANR的原因：keyDispatchingTimedOut
系统中活跃进程的CPU占用率，关键的一句：100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait；表示CPU占用满负荷了，其中绝大数是被iowait即I/O操作占用了。我们就可以大致得出是io操作导致的ANR。

限于篇幅有限，不在分析别的ANR类型。同时需要注意：并不是所有的ANR类型都有章可循，很多偶发的ANR受限于当时发生的环境或者系统Bug；因此对ANR，更应该强调预防而不是分析。

3、 ANR触发场景

InputDispatching Timeout ：输入事件分发超时5s未响应完毕；
BroadcastQueue Timeout ：前台广播在10s内、后台广播在20秒内未执行完成；
Service Timeout ：前台服务在20s内、后台服务在200秒内未执行完成；
ContentProvider Timeout ：内容提供者,在publish过超时10s；

4、 ANR触发场景源码分析

系统的ANR机制是如何运行的，ANR是如何被触发的呢？
我们先来说说Service，主要用于在后台处理一些耗时的逻辑，或者去执行某些需要长期运行的任务。但很多同志认为Service就可以执行耗时任务，这是一种误解，Service本身也运行于主线程，执行耗时任务同样会发生ANR。此处只分析Service Timeout的出发场景。

4.1 ANR的起源

Service的启动过程由ContextWrapper开始，我们直接步入重点环节ActiveServices..java中realStartServiceLocked方法

    // 此处仅列出精简之后的代码；
    private final void realStartServiceLocked(ServiceRecord r,ProcessRecord app, boolean execInFg) throws RemoteException {
        /**
         * 关键代码：发送延时消息，SERVICE_TIMEOUT_MSG，此处是Service ANR的源头
         */
        bumpServiceExecutingLocked(r, execInFg, "create");
        try {
            /**
             * 接下来真正的创建Service对象，并执行Service的onCreate()方法
             */
            app.thread.scheduleCreateService(r, r.serviceInfo,
                    mAm.compatibilityInfoForPackageLocked(r.serviceInfo.applicationInfo),
                    app.repProcState);
        } catch (DeadObjectException e) {
            Slog.w(TAG, "Application dead when creating service " + r);
            mAm.appDiedLocked(app);
            throw e;
        }
    }

其中bumpServiceExecutingLocked()方法又会调用到scheduleServiceTimeoutLocked()方法延时发送SERVICE_TIMEOUT_MSG消息。

    /**
     * 延时发送SERVICE_TIMEOUT_MSG消息，前、后台Service时间不一样。
     * @param proc
     */
    void scheduleServiceTimeoutLocked(ProcessRecord proc) {
        if (proc.executingServices.size() == 0 || proc.thread == null) {
            return;
        }
        long now = SystemClock.uptimeMillis();
        Message msg = mAm.mHandler.obtainMessage(
                ActivityManagerService.SERVICE_TIMEOUT_MSG);
        msg.obj = proc;
        mAm.mHandler.sendMessageAtTime(msg,
                proc.execServicesFg ? (now+SERVICE_TIMEOUT) : (now+ SERVICE_BACKGROUND_TIMEOUT));
    }

接下来调用到了ActivityThread.java的scheduleCreateService()方法，实际上使用Handler发送了一条msg，最终调用到ActivityThread.java的handleCreateService()方法

   private void handleCreateService(CreateServiceData data) {
        try {
            java.lang.ClassLoader cl = packageInfo.getClassLoader();
            // 创建Service对象
            service = (Service) cl.loadClass(data.info.name).newInstance();
        } catch (Exception e) {
        }
        try {
            // 调用Service的onCreate方法
            service.onCreate();
            mServices.put(data.token, service);
            // 移除SERVICE_TIMEOUT_MSG的消息
            ActivityManagerNative.getDefault().serviceDoneExecuting(
                        data.token, SERVICE_DONE_EXECUTING_ANON, 0, 0);
        } catch (Exception e) {
        }
    }

4.2 规定时间之内完成了方法的调用

ActivityManagerNative.getDefault().serviceDoneExecuting会执行到ActivityManagerService.java中的serviceDoneExecuting()方法，进而执行到ActiveService.java中的serviceDoneExecutingLocked()方法。此处意义：remove掉刚刚延时发送的Message。

 private void serviceDoneExecutingLocked(ServiceRecord r, boolean inDestroying,boolean finishing) {
        if (r.app.executingServices.size() == 0) {
            if (DEBUG_SERVICE || DEBUG_SERVICE_EXECUTING) Slog.v(TAG_SERVICE_EXECUTING,
                    "No more executingServices of " + r.shortName);
            // 关键代码：remove掉刚刚延时发送的Message，否则Message被执行，ANR就发生了；
            mAm.mHandler.removeMessages(ActivityManagerService.SERVICE_TIMEOUT_MSG, r.app);
        } else if (r.executeFg) {
            // Need to re-evaluate whether the app still needs to be in the foreground.
            for (int i=r.app.executingServices.size()-1; i>=0; i--) {
                if (r.app.executingServices.valueAt(i).executeFg) {
                    r.app.execServicesFg = true;
                    break;
                }
            }
        }
    }

4.3 规定时间之内未完成方法的调用，出现了ANR

而如果Message没有被mAm.mHandler（也就是ActivityManagerService中的MainHandler）及时remove掉，被执行的话就会出发ANR的发生；执行到ActivityManagerService中MainHandler的SERVICE_TIMEOUT_MSG然后调用到ActiveServices的serviceTimeout()方法，最终执行到ActivityManagerService的appNotResponding()方法。

    //非常重要的方法，代码多留了点。
    final void appNotResponding(ProcessRecord app, ActivityRecord activity,
                                ActivityRecord parent, boolean aboveSystem, final String annotation) {
        ArrayList<Integer> firstPids = new ArrayList<Integer>(5);
        SparseArray<Boolean> lastPids = new SparseArray<Boolean>(20);

        synchronized (this) {
            // Dump thread traces as quickly as we can, starting with "interesting" processes.
            firstPids.add(app.pid);

            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);
            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);
                        } else {
                            lastPids.put(pid, Boolean.TRUE);
                        }
                    }
                }
            }
        }

        // 获取ANR日志信息
        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");
        }

        final ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(true);

        File tracesFile = dumpStackTraces(true, firstPids, processCpuTracker, lastPids,
                NATIVE_STACKS_OF_INTEREST);

        String cpuInfo = null;
        if (MONITOR_CPU_USAGE) {
            updateCpuStatsNow();
            synchronized (mProcessCpuTracker) {
                cpuInfo = mProcessCpuTracker.printCurrentState(anrTime);
            }
            info.append(processCpuTracker.printCurrentLoad());
            info.append(cpuInfo);
        }

        info.append(processCpuTracker.printCurrentState(anrTime));

        Slog.e(TAG, info.toString());
        if (tracesFile == null) {
            // There is no trace file, so dump (only) the alleged culprit's threads to the log
            Process.sendSignal(app.pid, Process.SIGNAL_QUIT);
        }

        // 添加到DropBox，2.3之后出的功能，解决traces.txt被覆盖的问题
        addErrorToDropBox("anr", app, app.processName, activity, parent, annotation,
                cpuInfo, tracesFile, null);

        // 获取设置，确认是否需要弹出ANR提示框，需要的话弹出，不需要的话直接kill。
        boolean showBackground = Settings.Secure.getInt(mContext.getContentResolver(),
                Settings.Secure.ANR_SHOW_BACKGROUND, 0) != 0;

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

            if (!showBackground && !app.isInterestingToUserLocked() && app.pid != MY_PID) {
                // kill 进程
                app.kill("bg anr", true);
                return;
            }

            // Set the app's notResponding state, and look up the errorReportReceiver
            makeAppNotRespondingLocked(app,
                    activity != null ? activity.shortComponentName : null,
                    annotation != null ? "ANR " + annotation : "ANR",
                    info.toString());

            // Bring up the infamous App Not Responding dialog
            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);
            }
            // 去弹出ANR提示框。
            mUiHandler.sendMessage(msg);
        }
    }

流程总结：
1. Service创建之前会延迟发送一个消息，而这个消息就是ANR的起源；
2. Service创建完毕，在规定的时间之内执行完毕onCreate()方法就移除这个消息，就不会产生ANR了；
3. 在规定的时间之内没有完成onCreate()的调用，消息被执行，ANR发生。

Service Timeout流程图

5、其它

1、Service创建过程中对onCreate()埋下了ANR的起源，其中不能执行超过规定时间的操作，那是不是可以移到onStartCommand()方法中？

真是机智的同学，点个赞！然而事实并不是这样的，onStartCommond()方法的调用是在ActiveServices.java的sendServiceArgsLocked()，这个过程和onCreate()很类似，都会延时发送Message，然后在规定时间内执行完毕的话移除；没有完成的话发生ANR！

2、回到上面的问题：在《Multidex（二）之 Dex 预加载优化》中采用单独开进程执行Dex预加载优化的操作时，主进程在后台sleep()，为什么不会出现ANR呢？

答案是不是很清晰了：回忆下ANR的触发场景，此时主进程处于后台，无法响应按键、触摸等事件，同时此时也并没有Service等发生ANR的条件，因此主进程只是在后台等待，不会发生ANR。这种思路在MultiDex以及插件化方案中都有实践。

欢迎关注微信公众号：定期分享Java、Android干货！

欢迎关注

网友评论

7f5526d64fe6:“2. BroadcastQueue Timeout ：前台广播在10s内、后台广播在20秒内未执行完成；”

后台广播应该是在60秒内吧
// 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;
未来的理想:@捡豆哥多谢提醒
7f5526d64fe6:@双十二技术哥 android22及以上都是这样，ActivityManagerService中
未来的理想:这是哪个系统版本的？
李云龙_:666