本文共 6773 字，大约阅读时间需要 22 分钟。

应用做完后，有时候会发现应用比较卡或是反应比较慢，这时候就得去排查是什么原因导致的响应慢，我们的第一反应就是哪个函数执行是比较耗时的，那该怎么去排查耗时函数呢，在可能耗时的函数里答应执行时间么，那这个工作量就有点大了，也不利于维护，这里所以分享的就是如何去查找耗时函数，该如何去查找呢？这里先来看下代码实现，后面再来说说实现的原理：

代码实现

public class MethodMonitor implements Runnable {
       private Handler mLogHandler;    private static final String TAG="tangedegushi";    //分发和处理消息开始前的log    private static final String START = ">>>>> Dispatching";    //分发和处理消息结束后的log    private static final String END = "<<<<< Finished";    //记录方法执行时间    private long time;    //记录是否是耗时方法    private boolean isLargerTime;    //记录当前的耗时方法（方法所在的栈）    private String stackMessage;    //默认执行时间大于多少是耗时函数    private static final long MAX_TIME = 100;    private static MethodMonitor sInstance = new MethodMonitor();    private MethodMonitor() {
           HandlerThread t = new HandlerThread("monitorMethod");        t.start();        mLogHandler = new Handler(t.getLooper());    }    public static void monitorTakeUpTime(){
           Looper.getMainLooper().setMessageLogging(new Printer() {
               @Override            public void println(String x) {
                   if (x.startsWith(START)) {
                       sInstance.addMonitor();                }                if (x.startsWith(END)) {
                       sInstance.removeMonitor();                }            }        });    }    private void addMonitor() {
           isLargerTime = false;        time = System.currentTimeMillis();        mLogHandler.postDelayed(this, MAX_TIME);    }    private void removeMonitor() {
           mLogHandler.removeCallbacks(this);        if (isLargerTime) {
               Log.e(TAG, "卡顿时间 = "+(System.currentTimeMillis() - time)+"  卡顿函数 = "+stackMessage);        }    }    @Override    public void run() {
           StackTraceElement[] stackTrace = Looper.getMainLooper().getThread().getStackTrace();        for (StackTraceElement st : stackTrace) {
               // 过滤出自己应用的            if (st.toString().contains("com.ubtechinc.cruzr.")) {
                   isLargerTime = true;                stackMessage = st.toString();            }        }    }}

使用很简单，在启动应用的时候调用MethodMonitor.monitorTakeUpTime()，这样就可以看到耗时函数的输出，以及函数执行所耗费的时间，看完实现后，再来说说这里实现的的原理，这里利用的主要是Android的Looper，Looper里面有对外提供打印日志的方法setMessageLogging（），只需往里面设置即可，设置完后，会在Looper的loop（）方法里面使用到，这里就来看看loop这个方法：

原理讲解

public static void loop() {
           final Looper me = myLooper();        if (me == null) {
               throw new RuntimeException("No Looper; Looper.prepare() wasn't called on this thread.");        }        final MessageQueue queue = me.mQueue;        // Make sure the identity of this thread is that of the local process,        // and keep track of what that identity token actually is.        Binder.clearCallingIdentity();        final long ident = Binder.clearCallingIdentity();        // Allow overriding a threshold with a system prop. e.g.        // adb shell 'setprop log.looper.1000.main.slow 1 && stop && start'        final int thresholdOverride =                SystemProperties.getInt("log.looper."                        + Process.myUid() + "."                        + Thread.currentThread().getName()                        + ".slow", 0);        boolean slowDeliveryDetected = false;        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);            }            final long traceTag = me.mTraceTag;            long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;            long slowDeliveryThresholdMs = me.mSlowDeliveryThresholdMs;            if (thresholdOverride > 0) {
                   slowDispatchThresholdMs = thresholdOverride;                slowDeliveryThresholdMs = thresholdOverride;            }            final boolean logSlowDelivery = (slowDeliveryThresholdMs > 0) && (msg.when > 0);            final boolean logSlowDispatch = (slowDispatchThresholdMs > 0);            final boolean needStartTime = logSlowDelivery || logSlowDispatch;            final boolean needEndTime = logSlowDispatch;            if (traceTag != 0 && Trace.isTagEnabled(traceTag)) {
                   Trace.traceBegin(traceTag, msg.target.getTraceName(msg));            }            final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;            final long dispatchEnd;            try {
                   msg.target.dispatchMessage(msg);                dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;            } finally {
                   if (traceTag != 0) {
                       Trace.traceEnd(traceTag);                }            }            if (logSlowDelivery) {
                   if (slowDeliveryDetected) {
                       if ((dispatchStart - msg.when) <= 10) {
                           Slog.w(TAG, "Drained");                        slowDeliveryDetected = false;                    }                } else {
                       if (showSlowLog(slowDeliveryThresholdMs, msg.when, dispatchStart, "delivery",                            msg)) {
                           // Once we write a slow delivery log, suppress until the queue drains.                        slowDeliveryDetected = true;                    }                }            }            if (logSlowDispatch) {
                   showSlowLog(slowDispatchThresholdMs, dispatchStart, dispatchEnd, "dispatch", msg);            }            if (logging != null) {
                   logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);            }            // Make sure that during the course of dispatching the            // identity of the thread wasn't corrupted.            final long newIdent = Binder.clearCallingIdentity();            if (ident != newIdent) {
                   Log.wtf(TAG, "Thread identity changed from 0x"                        + Long.toHexString(ident) + " to 0x"                        + Long.toHexString(newIdent) + " while dispatching to "                        + msg.target.getClass().getName() + " "                        + msg.callback + " what=" + msg.what);            }            msg.recycleUnchecked();        }    }

在这个方法中找到logging这个变量，这个变量就是我们通过setMessageLogging（）设置进来的，可以看到logging在输出的字符串中有">>>>> Dispatching"和"<<<<< Finished"，在这两个输出之间就是方法的执行时间，所以在这里是可以打印出所有方法的执行时间的，要找出耗时函数，这里就需要过滤一下，上面代码中所取的耗时时间大于100ms，这个可以自己定义，loop()方法中消息的分发主要是在msg.target.dispatchMessage(msg);中执行的，简单实用的一个工具类。

转载地址：http://wzhai.baihongyu.com/