Android卡顿自动化检测实现

最近在看一篇Android文章的时候看到一种检测Android卡顿的线上实现方案，然后自己动手简单实现了下。

它的原理源于Android的消息处理机制，一个线程不管有多少Handler，它只会有一个Looper存在，主线程执行的任何代码都会通过Looper.loop()方法执行。而在Looper函数中，它有一个mLogging对象，这个对象在每个message处理前后都会被调用。主线程发生了卡顿，那一定是在dispatchMessage()方法中执行了耗时操作。那么，我们就可以通过这个mLogging对象对dispatchMessage()进行监控。

Looper的消息循环方法loop的实现：

public static void loop() {
        final Looper me = myLooper();
        final MessageQueue queue = me.mQueue;

        for (;;) {
            Message msg = queue.next(); // might block
            if (msg == null) {
                // No message indicates that the message queue is quitting.
                return;
            }

            // This must be in a local variable, in case a UI event sets the logger
            final Printer logging = me.mLogging;
            if (logging != null) {
                logging.println(">>>>> Dispatching to " + msg.target + " " +
                        msg.callback + ": " + msg.what);
            }
           
            ...

            try {
                msg.target.dispatchMessage(msg);
            } catch (Exception exception) {
                
            } finally {
                
            }
            
            ...

            if (logging != null) {
                logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
            }

        }
    }

在Looper的loop()方法中，在其执行每一个消息的前后都由logging进行了一次打印输出。可以看到，在执行消息前是输出的">>>>> Dispatching to "，在执行消息后是输出的"<<<<< Finished to ",它们打印的日志是不一样的，我们就可以由此来判断消息执行的前后时间点。

因此，具体实现步骤：

• 1、首先，我们需要使用Looper.getMainLooper().setMessageLogging()去设置我们自己的Printer实现类去打印输出logging。这样，在每个message执行的之前和之后都会调用我们设置的这个Printer实现类。
• 2、如果我们匹配到">>>>> Dispatching to "之后，我们就可以执行一行代码：也就是在指定的时间阈值之后，我们在子线程去执行一个任务，这个任务就是去获取当前主线程的堆栈信息以及当前的一些场景信息，比如：内存大小、手机、网络状态等。
• 3、如果在指定的阈值之内匹配到了"<<<<< Finished to "，那么说明message就被执行完成了，则表明此时没有产生我们认为的卡顿效果，那我们就可以将这个子线程任务取消掉。

通过上述实现方案我们初步代码实现：

import android.os.Looper;
import android.util.Log;
import android.util.LogPrinter;

public class LogMonitorPrinter extends LogPrinter {
    private static final String TAG = "LogMonitorPrinter";
    private long beginTime;
    private int timeoutInterval = 1000;
    private MonitorThread monitorThread;

    /**
     * Create a new Printer that sends to the log with the given priority
     * and tag.
     *
     * @param priority The desired log priority:
     *                 {@link Log#VERBOSE Log.VERBOSE},
     *                 {@link Log#DEBUG Log.DEBUG},
     *                 {@link Log#INFO Log.INFO},
     *                 {@link Log#WARN Log.WARN}, or
     *                 {@link Log#ERROR Log.ERROR}.
     * @param tag      A string tag to associate with each printed log statement.
     */
    public LogMonitorPrinter(int priority, String tag) {
        super(priority, tag);
    }


    public void setTimeoutInterval(int interval) {
        this.timeoutInterval = interval;
    }

    @Override
    public void println(String x) {
        if (x.startsWith(">>>>> Dispatching to")) {
            beginTime = System.currentTimeMillis();
            monitorThread = new MonitorThread(timeoutInterval);
            monitorThread.start();
        }

        if (x.startsWith("<<<<< Finished to")) {
            long taskTime = System.currentTimeMillis() - beginTime;
            monitorThread.interrupt();
            if (taskTime > timeoutInterval) {
                Log.w(TAG, "taskTime: " + taskTime);
            }
        }
        super.println(x);
    }

    private static String getMainStackTrace() {
        StackTraceElement[] stackTraceElements = Looper.getMainLooper().getThread().getStackTrace();
        StringBuilder sb = new StringBuilder();
        for (StackTraceElement element : stackTraceElements) {
            sb.append(element.toString());
            sb.append("\n");
        }
        return sb.toString();
    }

    static class MonitorThread extends Thread {
        private long interval;

        public MonitorThread(int interval) {
            this.interval = interval;
        }

        @Override
        public void run() {
            try {
                Thread.sleep(interval);
            } catch (InterruptedException e) {
                return;
            }

            Log.w(TAG, getMainStackTrace());
        }
    }
}

设置主线程Looper的mLogging：

Looper.getMainLooper().setMessageLogging(new LogMonitorPrinter(Log.DEBUG, "Monitor"));

可以在我们自己应用的Application onCreate()方法中设置自定义的mLogging。

那么，在系统中Looper的mLogging是如何设置的呢？跟踪Looper的setMessageLogging()方法可以看到其实是在ActivityThread的main方法中调用的，只是系统关闭了该设置：

        if (false) {
            Looper.myLooper().setMessageLogging(new
                    LogPrinter(Log.DEBUG, "ActivityThread"));
        }

上述代码通过验证可以获取到卡顿任务的堆栈信息，但是在println中每次任务都要new Thread，频繁创建和销毁线程会导致性能问题，因此我们可以通过创建线程池的方式对线程进行复用，此处也可以考虑使用HandlerThread的方式实现。

系统源码在ActivityThread中可以看到对mLogging的设置是关闭的，因为log信息的输出也会消耗cpu性能，因此实际使用时可以只输出卡顿信息。

 

此方案如果要部署到线上，还需要考虑采集信息的上传，比如对用户进行抽样采集，堆栈信息的去重，文件压缩等，并选择合适的时机上传等。

 

参考：https://juejin.im/post/5e41fb7de51d4526c80e9108