AndroidFps帧率监控

一、为什么卡顿监控如此重要

一个APP从0-1的阶段是疯狂堆功能的阶段，可能不会考虑性能问题和代码规范问题，但是一旦这个APP做到成熟之后我们就需要来考虑这个APP的性能问题了，启动是否卡顿，滑动是否流畅，这些都是对于用户体验至关重要的东西，这也是一个APP是否成熟的重要标准和指标。

二、我们能做什么

提到卡顿和流畅就不得不提一个指标就是FPS，一般卡顿问题是主线程执行了太多的耗时操作，例如渲染，布局，输入等，阻塞了主线程的消息循环导致单个消息处理过程，消息挤压过多那么掉帧就会很明显，用户也就看到你的APP卡的不行，降低用户信任。解决卡顿问题很重要，但是更重要的是我们可以监控到卡顿，FPS就是这样的指标，下面来说下我们怎么来自己计算FPS。

三、监控原理

我们人眼所能看到的连续画面，其实可以简单理解为是一张一张的图片形成的，如果按照一秒60张，算下来16ms就是一张新的图片，这个过程是很快速的，但是如果我们应用卡顿发生了，那么可能在100ms，200ms，500ms等就展示了一张图片，那么用户就会明显看到卡顿了，那我们就可以知道一个计算公式：

// 帧率
帧率 = (单位图片次数) / (一张图片的耗时)

我们可以定义一个作为帧率的概念，用FPS来标识，也就是在一秒内能展示多少张图片的意思，单位时间可以看成1s，一张图片的的耗时可以跟机器硬件关联起来，例如之前的手机是16.6ms来展示一帧的（现在由于有高刷的情况 ，这个值会更低）。 从这个公式我们就知道了，单位时间是不变的，一张图片的耗时是跟设备有关系的，设备越好，值越低，会让帧率越高，帧率越高我们的体验就会更好，越流畅。 那我们扩展下这个公式就可以这样展示：

// 帧率
帧率 = (从第一张到最后一张图片总次数) / （从第一张到最后一张的总时间）
// 变成代码跟清晰
fps = （sumFrames - lastSumFrames）/ (frameCostTimes - lastFrameCostTimes)

这样它的基本原理，计算规则我们就都清楚了，我们接下来就找到合适的地方按照此规则计算即可， 伪代码类似于这样：

// 首先定义四个变量，也就是代表上述公式计算的主要值
long sumFrames = 0L;
long lastSumFrames = 0L;
long frameCostTimes = 0L;
long lastFrameCostTimes = 0L;

fun calcFps() {
    frameCostTimes = xxx //这个应该怎么计算才是核心
    sumFrames += 1
    if (duration > 200) {// 不需要每次都计算，隔200间隔再计算
        val fps = (sumFrames - lastSumFrames) / (frameCostTime - lastFrameCostTime)
        lastSumFrames = sumFrames
    }
}

四、代码实战

我们要找到Android代码中帧率变化的地方，参考了Android官方文档，和Matrix中监控的实现，有以下集中方法可以来做：

1. 使用Choreographer来做，这个是Android系统提供的和硬件Vsync信号（也就是16.6ms的硬件来源）接收和处理的地方
2. 7.0以上的设备，官方直接提供了API，可以用addOnFrameMetricsAvailableListener来做
3. 参考Matrix中的方法，因为所有的绘制消息，触摸消息，都是跟主线程的looper有关系，那么可以监听主线程的消息来看每个消息的耗时从而计算帧率

4.1 Looper方式

结合Matrix源码，是7.0以上的版本使用官方的API，7.0以下的版本是通过主线程的消息循环，那么我们可以参照这种方式来讲一下它的具体实现，至于Choreographer的方式，消息循环也涉及到就在说了。 我们可以看下Matrix中的代码是如何来做的：

private synchronized void resetPrinter() {
    ...
    // 设置了logging
    looper.setMessageLogging(printer = new LooperPrinter(originPrinter));
    ...
}

我们再看下LooperPrinter干了什么，看下Looper的代码就更清晰了

public void println(String x) {
    if (null != origin) {
        origin.println(x);
        if (origin == this) {
            throw new RuntimeException(TAG + " origin == this");
        }
    }

    if (!isHasChecked) {
        isValid = x.charAt(0) == '>' || x.charAt(0) == '<';
        isHasChecked = true;
        if (!isValid) {
            MatrixLog.e(TAG, "[println] Printer is inValid! x:%s", x);
        }
    }

    if (isValid) {
        // 它会根据Looper里面的消息，来判断是消息处理前和后，这样就可以来做消息的耗时统计了
        dispatch(x.charAt(0) == '>', x);
    }
}

// 消息处理前
logging.println(">>>>> Dispatching to " + msg.target + " " +
                        msg.callback + ": " + msg.what);
......
// 消息处理后
logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);

那我们接着看UIThreadMonitor.java的代码就知道前后是怎么处理的了

// 处理消息前
private void dispatchBegin() {
    token = dispatchTimeMs[0] = System.nanoTime();
    dispatchTimeMs[2] = SystemClock.currentThreadTimeMillis();
    if (config.isAppMethodBeatEnable()) {
        AppMethodBeat.i(AppMethodBeat.METHOD_ID_DISPATCH);
    }
    synchronized (observers) {
        for (LooperObserver observer : observers) {
            if (!observer.isDispatchBegin()) {
                observer.dispatchBegin(dispatchTimeMs[0], dispatchTimeMs[2], token);
            }
        }
    }
    if (config.isDevEnv()) {
        MatrixLog.d(TAG, "[dispatchBegin#run] inner cost:%sns", System.nanoTime() - token);
    }
}

// 处理消息后
private void dispatchEnd() {
    long traceBegin = 0;
    if (config.isDevEnv()) {
        traceBegin = System.nanoTime();
    }

    if (config.isFPSEnable() && !useFrameMetrics) {
        // 开始时间
        long startNs = token;
        // Vsync信号接收的时间
        long intendedFrameTimeNs = startNs;
        if (isVsyncFrame) {
            doFrameEnd(token);
            intendedFrameTimeNs = getIntendedFrameTimeNs(startNs);
        }

        long endNs = System.nanoTime();

        synchronized (observers) {
            for (LooperObserver observer : observers) {
                if (observer.isDispatchBegin()) {
                    // 最重要的代码是在这里
                    observer.doFrame(AppActiveMatrixDelegate.INSTANCE.getVisibleScene(), startNs, endNs, isVsyncFrame, intendedFrameTimeNs, queueCost[CALLBACK_INPUT], queueCost[CALLBACK_ANIMATION], queueCost[CALLBACK_TRAVERSAL]);
                }
            }
        }
    }

    if (config.isEvilMethodTraceEnable() || config.isDevEnv()) {
        dispatchTimeMs[3] = SystemClock.currentThreadTimeMillis();
        dispatchTimeMs[1] = System.nanoTime();
    }

    AppMethodBeat.o(AppMethodBeat.METHOD_ID_DISPATCH);

    synchronized (observers) {
        for (LooperObserver observer : observers) {
            if (observer.isDispatchBegin()) {
                observer.dispatchEnd(dispatchTimeMs[0], dispatchTimeMs[2], dispatchTimeMs[1], dispatchTimeMs[3], token, isVsyncFrame);
            }
        }
    }

    this.isVsyncFrame = false;

    if (config.isDevEnv()) {
        MatrixLog.d(TAG, "[dispatchEnd#run] inner cost:%sns", System.nanoTime() - traceBegin);
    }
}

然后它是在FrameTracer来统一处理的

private void notifyListener(final String focusedActivity, final long startNs, final long endNs, final boolean isVsyncFrame,
                                final long intendedFrameTimeNs, final long inputCostNs, final long animationCostNs, final long traversalCostNs) {
        long traceBegin = System.currentTimeMillis();
        try {
            // intendedFrameTimeNs是接收Vsync信号接收的时间，endNs是实际的帧时间
            final long jitter = endNs - intendedFrameTimeNs;
            // 计算丢帧
            final int dropFrame = (int) (jitter / frameIntervalNs);
            ....
            synchronized (listeners) {
                for (final IDoFrameListener listener : listeners) {
                    if (config.isDevEnv()) {
                        listener.time = SystemClock.uptimeMillis();
                    }
                    if (null != listener.getExecutor()) {
                        if (listener.getIntervalFrameReplay() > 0) {
                            listener.collect(focusedActivity, startNs, endNs, dropFrame, isVsyncFrame,
                                    intendedFrameTimeNs, inputCostNs, animationCostNs, traversalCostNs);
                        } else {
                            listener.getExecutor().execute(new Runnable() {
                                @Override
                                public void run() {
                                    // 真正处理计算帧率的地方；
                                    listener.doFrameAsync(focusedActivity, startNs, endNs, dropFrame, isVsyncFrame,
                                            intendedFrameTimeNs, inputCostNs, animationCostNs, traversalCostNs);
                                }
                            });
                        }
                    } else {
                        listener.doFrameSync(focusedActivity, startNs, endNs, dropFrame, isVsyncFrame,
                                intendedFrameTimeNs, inputCostNs, animationCostNs, traversalCostNs);
                    }

                    if (config.isDevEnv()) {
                        listener.time = SystemClock.uptimeMillis() - listener.time;
                        MatrixLog.d(TAG, "[notifyListener] cost:%sms listener:%s", listener.time, listener);
                    }
                }
            }
        } finally {
            long cost = System.currentTimeMillis() - traceBegin;
            if (config.isDebug() && cost > frameIntervalNs) {
                MatrixLog.w(TAG, "[notifyListener] warm! maybe do heavy work in doFrameSync! size:%s cost:%sms", listeners.size(), cost);
            }
        }
    }

我们再来看下FrameDecoration类，它是怎么来计算FPS的

@Override
public void doFrameAsync(String focusedActivity, long startNs, long endNs, int dropFrame, boolean isVsyncFrame, long intendedFrameTimeNs, long inputCostNs, long animationCostNs, long traversalCostNs) {
    super.doFrameAsync(focusedActivity, startNs, endNs, dropFrame, isVsyncFrame, intendedFrameTimeNs, inputCostNs, animationCostNs, traversalCostNs);

    sumFrameCost += (dropFrame + 1) * frameIntervalMs;
    sumFrames += 1;
    float duration = sumFrameCost - lastCost[0];
    ....

    long collectFrame = sumFrames - lastFrames[0];
    if (duration >= 200) {
        // 这就是fps计算的地方
        final float fps = Math.min(maxFps, 1000.f * collectFrame / duration);
        updateView(view, fps, belongColor,
                dropLevel[FrameTracer.DropStatus.DROPPED_NORMAL.index],
                dropLevel[FrameTracer.DropStatus.DROPPED_MIDDLE.index],
                dropLevel[FrameTracer.DropStatus.DROPPED_HIGH.index],
                dropLevel[FrameTracer.DropStatus.DROPPED_FROZEN.index],
                sumDropLevel[FrameTracer.DropStatus.DROPPED_NORMAL.index],
                sumDropLevel[FrameTracer.DropStatus.DROPPED_MIDDLE.index],
                sumDropLevel[FrameTracer.DropStatus.DROPPED_HIGH.index],
                sumDropLevel[FrameTracer.DropStatus.DROPPED_FROZEN.index]);
        belongColor = bestColor;
        lastCost[0] = sumFrameCost;
        lastFrames[0] = sumFrames;
        mainHandler.removeCallbacks(updateDefaultRunnable);
        mainHandler.postDelayed(updateDefaultRunnable, 250);
    }
}

这样我们就知道了它是怎么计算FPS的了

final float fps = Math.min(maxFps, 1000.f * collectFrame / duration);
// 和我们上述自己的公式对比一下
fun calcFps() {
    frameCostTimes = xxx //这个应该怎么计算才是核心
    sumFrames += 1
    if (duration > 200) {// 不需要每次都计算，隔200间隔再计算
        val fps = (sumFrames - lastSumFrames) / (frameCostTime - lastFrameCostTime)
        lastSumFrames = sumFrames
    }
}

和我们自己的公式对比下就知道了，我们就可以知道了，它是在消息循环监听每一次消息的的耗时，通过这个来计算的累计帧和耗时，还有一个问题Looper为啥可以监控到FPS呢，它和vsync也没关系啊，我们看下UIThreadMonitor.java这个类就知道了，具体代码是：

private long getIntendedFrameTimeNs(long defaultValue) {
    try {
        return ReflectUtils.reflectObject(vsyncReceiver, "mTimestampNanos", defaultValue);
    } catch (Exception e) {
        e.printStackTrace();
        MatrixLog.e(TAG, e.toString());
    }
    return defaultValue;
}

它是反射获取了Choreographer中的mTimestampNanos字段，它就是帧预期结束的时间，因为所有的绘制，动画，手势等都是Choreographer也都是在主线程里监听请求Vsync然后再主线程里处理的，所以我们可以反射这个值来作为帧结束的时间，这样就可以知道FPS是怎么计算的了。

4.2 addOnFrameMetricsAvailableListener 方式

这个方式就更简单了，直接看官方API试用下就可以了，只支持7.0以上的版本，示例代码：

val frameIntervalNanos = 1 / getWindowManager().getDefaultDisplay().getRefreshRate() * 1000000000
window.addOnFrameMetricsAvailableListener({ window, frameMetrics, dropCountSinceLastInvocation ->
    val frameMetricsCopy = FrameMetrics(frameMetrics)
    val vsyncTime = frameMetricsCopy.getMetric(FrameMetrics.VSYNC_TIMESTAMP)
    val intentedVsyncTime = frameMetricsCopy.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)
    val jitter = vsyncTime - intentedVsyncTime
    val dropFrame: Int = (jitter / frameIntervalNanos).toInt()

    // 不丢帧时正常帧也要算进去所以要+1
    sumFrameCost += ((dropFrame + 1) * frameIntervalNanos / 1000000)
    sumFrames += 1

    val duration = sumFrameCost - lastDuration
    val collectFrame = sumFrames - lastFrames

    if (duration >= 200) {
        val fps = 1000.0f * collectFrame / duration
        Log.i("hellokai", ">>>>>>>fps->$fps")
        lastFrames = sumFrame
        lastDuration = sumFrameCost
    }
}, Handler(Looper.getMainLooper()))

使用起来很简单，主要的核心计算方式也是上面的公式。

五、总结

这样我们就知道如何自己来计算FPS了，其实核心代码都是一样的，主要是要找到Vsync所给的帧回调的时间来做差值，才能计算出FPS是多少。简单总结下，示例代码为：

import android.app.Activity
import android.os.Build
import android.os.Handler
import android.os.Looper
import android.util.Log
import android.view.Choreographer
import android.view.FrameMetrics
import java.lang.reflect.Field

class FpsTrace {
    private var start = 0L
    var fps = 0f
    private set

    private var sumFrameCost = 0L
    private var sumFrame = 0L
    private var lastDuration = 0L
    private var lastFrames = 0L

    private var refreshRate: Float = 0f
    private var frameIntervalNanos: Float = 0f

    fun setUp(activity: Activity) {
        refreshRate = activity.windowManager.defaultDisplay.refreshRate
        frameIntervalNanos = 1 / refreshRate * 1000000000
        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.N) {
            activity.window.addOnFrameMetricsAvailableListener({ window, frameMetrics, dropCountSinceLastInvocation ->
                val frameMetricsCopy = FrameMetrics(frameMetrics)
                val vsyncTime = frameMetricsCopy.getMetric(FrameMetrics.VSYNC_TIMESTAMP)
                val intentedVsyncTime = frameMetricsCopy.getMetric(FrameMetrics.INTENDED_VSYNC_TIMESTAMP)
                val jitter = vsyncTime - intentedVsyncTime
                val dropFrame = (jitter / frameIntervalNanos).toLong()
                calcFps(dropFrame)
            }, Handler(Looper.getMainLooper()))
        } else {
            Handler(Looper.getMainLooper()).apply {
                looper.setMessageLogging {
                    if (it.toString().startsWith(">>>>>")) {
                        startMethod(it)
                    }
                    if (it.toString().startsWith("<<<<<")) {
                        endMethod(it)
                    }
                }
            }
        }
    }

    private fun startMethod(it: String) {
        start = System.nanoTime()
    }

    private fun endMethod(it: String) {
        val intentStart = getIntendedFrameTimeNs(start)
        val jitter = System.nanoTime() - intentStart
        val dropFrame = (jitter / frameIntervalNanos).toLong()
        calcFps(dropFrame)
    }

    private fun calcFps(dropFrame: Long) {
        sumFrameCost += ((dropFrame + 1) * frameIntervalNanos / 1000000).toLong()
        sumFrame += 1

        val duration = sumFrameCost - lastDuration
        val collectFrame = sumFrame - lastFrames
        if (duration >= 200) {
            fps = Math.min(refreshRate, 1000.0f * collectFrame / duration)
            Log.i("hellokai", ">>>>>>>fps->$fps,")
            lastFrames = sumFrame
            lastDuration = sumFrameCost
        }
    }

    private fun getIntendedFrameTimeNs(defaultValue: Long): Long {
        val choreographer = Choreographer.getInstance()
        val getDeclaredField = Class::class.java.getDeclaredMethod("getDeclaredField", String::class.java)
        val field = getDeclaredField.invoke(choreographer.javaClass, "mDisplayEventReceiver") as Field
        field.isAccessible = true
        val vsyncReceiver = field.get(choreographer)
        return ReflectUtils.reflectObject(vsyncReceiver, "mTimestampNanos", defaultValue)
    }
}

六、扩展

卡顿的问题我们想知道到底是哪个代码产生的，我们可以仿照Matrix中的实现再加一些代码，在卡顿的时候直接打印当前堆栈即可：

//可以用一个handler来处理
private val handlerThread = HandlerThread("MyHandlerThread")
lateinit var handler: Handler
private val anrRunnable = Runnable {
    val stackTrace = Looper.getMainLooper().thread.stackTrace
    val dumpStack: String = getWholeStack(stackTrace)
    Log.i("hellokai", "Anr--------start-------\n")
    Log.i("hellokai", "Anr-------->$dumpStack")
    Log.i("hellokai", "Anr--------end-------\n")
}
...

// 利用上面的消息开始和结束的代码，发送消息和移除消息
private fun startMethod(it: String) {
    handler.postDelayed(anrRunnable, 5 * 1000L)
    ...
}

private fun endMethod(it: String) {
    Log.i("hellokai", "endMethod:$it")
    handler.removeCallbacks(anrRunnable)
    ...
}

这样就可以了。