程序流畅度是很重要的一个指标,重要是因为用户可以直观体验到,为啥别人家的程序都是如丝般顺滑( •̀ ω •́ )✧( •̀ ω •́ )✧( •̀ ω •́ )✧,今天就来聊聊系统是如何判断程序卡顿。
不知道你曾注意过这样一条系统日志
Choreographer(1434): Skipped 35 frames! The application may be doing too much work on its main thread.
当出现这条信息,意味着我们程序执行过程中出现了卡顿,需要进一步优化。
一、黄油计划(Project Butter)
android在不同的版本都会优化“UI的流畅性”问题,但是直到在android 4.1版本中做了有效的优化,这就是Project Butter,所谓的黄油计划,android工程师真会起名字。
Project Butter加入了三个核心元素:VSYNC、Triple Buffer和Choreographer。其中VSYNC是理解Project Buffer的核心。VSYNC是Vertical Synchronization的缩写 也就是“垂直同步”
1.1.没有VSYNC前
- 时间从0开始,进入第一个16ms:Display显示第0帧,CPU处理完第一帧后,GPU紧接其后处理继续第一帧。三者互不干扰,一切正常。
- 时间进入第二个16ms:因为早在上一个16ms时间内,第1帧已经由CPU,GPU处理完毕。故Display可以直接显示第1帧。显示没有问题。但在本16ms期间,CPU和GPU却并未及时去绘制第2帧数据(注意前面的空白区),而是在本周期快结束时,CPU/GPU才去处理第2帧数据。
- 时间进入第3个16ms,此时Display应该显示第2帧数据,但由于CPU和GPU还没有处理完第2帧数据,故Display只能继续显示第一帧的数据,结果使得第1帧多画了一次(对应时间段上标注了一个Jank)。
- 通过上述分析可知,此处发生Jank的关键问题在于,为何第1个16ms段内,CPU/GPU没有及时处理第2帧数据?原因很简单,CPU可能是在忙别的事情(比如某个应用通过sleep固定时间来实现动画的逐帧显示),不知道该到处理UI绘制的时间了。可CPU一旦想起来要去处理第2帧数据,时间又错过了
1.2.引入了VSYNC
Vsync提高了图形性能,为了确保整个体验的帧速率一致,从Android 4.1开始将vsync定时扩展到Android框架处理的所有绘图和动画。一切都与16毫秒的vsync“心跳”相协调——应用程序渲染、触摸事件、屏幕合成和显示刷新——因此帧不会超前或落后。
二、应用卡顿检测
Android系统每隔16.6ms发出VSYNC信号,来通知界面进行输入、动画、绘制等动作,每一次同步的周期为16.6ms,代表一帧的刷新频率,理论上来说两次回调的时间周期应该在16.6ms,如果超过了16.6ms我们则认为发生了卡顿,利用两次回调间的时间周期来判断是否发生卡顿 这个方案的原理主要是通过Choreographer类设置它的FrameCallback函数,当每一帧被渲染时会触发回调FrameCallback, FrameCallback回调void doFrame (long frameTimeNanos)函数。一次界面渲染会回调doFrame方法,如果两次doFrame之间的间隔大于16.6ms说明发生了卡顿
2.1.Choreographer类
监控应用的流畅度一般都是通过Choreographer类的postFrameCallback方法注册一个VSYNC回调事件
public static void start(final Builder builder) { Choreographer.getInstance().postFrameCallback(new Choreographer.FrameCallback() { long lastFrameTimeNanos = 0; long currentFrameTimeNanos = 0; @Override public void doFrame(long frameTimeNanos) { if (lastFrameTimeNanos == 0) { lastFrameTimeNanos = frameTimeNanos; LogMonitor.getInstance().setFrequency(builder.frame * 17 / 2); if (builder.targetPackageName != null) { LogMonitor.getInstance().setTargetPackageName(builder.targetPackageName); } LogMonitor.getInstance().setDumpListener(builder.onDumpListener); } currentFrameTimeNanos = frameTimeNanos; skipFrameCount = skipFrameCount(lastFrameTimeNanos, currentFrameTimeNanos, deviceRefreshRateMs); LogMonitor.getInstance().setFrame(skipFrameCount); if (LogMonitor.getInstance().isMonitor()) { LogMonitor.getInstance().removeMonitor(); } LogMonitor.getInstance().startMonitor(); lastFrameTimeNanos = currentFrameTimeNanos; Choreographer.getInstance().postFrameCallback(this); } }); }
postFrameCallback(FrameCallback callback)方法
public void postFrameCallback(FrameCallback callback) { postFrameCallbackDelayed(callback, 0); }...... public void postFrameCallbackDelayed(FrameCallback callback, long delayMillis) { if (callback == null) { throw new IllegalArgumentException("callback must not be null"); } postCallbackDelayedInternal(CALLBACK_ANIMATION, callback, FRAME_CALLBACK_TOKEN, delayMillis); }
postFrameCallback最终调用了postCallbackDelayedInternal()方法,我们在跟踪进去这个方法
private void postCallbackDelayedInternal(int callbackType, Object action, Object token, long delayMillis) { if (DEBUG_FRAMES) { Log.d(TAG, "PostCallback: type=" + callbackType + ", action=" + action + ", token=" + token + ", delayMillis=" + delayMillis); } synchronized (mLock) { final long now = SystemClock.uptimeMillis(); final long dueTime = now + delayMillis; mCallbackQueues[callbackType].addCallbackLocked(dueTime, action, token); if (dueTime <= now) { scheduleFrameLocked(now); } else { Message msg = mHandler.obtainMessage(MSG_DO_SCHEDULE_CALLBACK, action); msg.arg1 = callbackType; msg.setAsynchronous(true); mHandler.sendMessageAtTime(msg, dueTime); } } }
postCallbackDelayedInternal方法中首选通过 mCallbackQueues[callbackType].addCallbackLocked(dueTime, action, token);将我们注册的回调接口添加到mCallbackQueues队列中。每种类型的callback按照设置的执行时间(dueTime)顺序排序分别保存在一个单链表中。
之后判断执行时间是否为当前时间,如果是直接调用scheduleFrameLocked(now);否则发送一个MSG_DO_SCHEDULE_CALLBACK一个消息,其实发送信息最后也是调用scheduleFrameLocked(now)方法,所以我们直接看这个方法的代码
private void scheduleFrameLocked(long now) { if (!mFrameScheduled) { mFrameScheduled = true; if (USE_VSYNC) {//默认为true if (DEBUG_FRAMES) { Log.d(TAG, "Scheduling next frame on vsync."); } // If running on the Looper thread, then schedule the vsync immediately, // otherwise post a message to schedule the vsync from the UI thread // as soon as possible. if (isRunningOnLooperThreadLocked()) { //是否是主线程 scheduleVsyncLocked(); } else {//发消息给主线程 Message msg = mHandler.obtainMessage(MSG_DO_SCHEDULE_VSYNC); msg.setAsynchronous(true); mHandler.sendMessageAtFrontOfQueue(msg); } } else { final long nextFrameTime = Math.max( mLastFrameTimeNanos / TimeUtils.NANOS_PER_MS + sFrameDelay, now); if (DEBUG_FRAMES) { Log.d(TAG, "Scheduling next frame in " + (nextFrameTime - now) + " ms."); } Message msg = mHandler.obtainMessage(MSG_DO_FRAME); msg.setAsynchronous(true); mHandler.sendMessageAtTime(msg, nextFrameTime); } } }
USE_VSYNC 默认是 true,表示默认开启垂直同步
private static final boolean USE_VSYNC = SystemProperties.getBoolean( "debug.choreographer.vsync", true);
scheduleVsyncLocked方法
private void scheduleVsyncLocked() { mDisplayEventReceiver.scheduleVsync(); }....../** * Schedules a single vertical sync pulse to be delivered when the next * display frame begins. */ public void scheduleVsync() { if (mReceiverPtr == 0) { Log.w(TAG, "Attempted to schedule a vertical sync pulse but the display event " + "receiver has already been disposed."); } else { nativeScheduleVsync(mReceiverPtr); } }
最终通过调native方法nativeScheduleVsync(mReceiverPtr)向底层注册我们的回调事件。 到此我们向系统注册“垂直同步”事件的流程已经结束。所有的流程如下:
接收VSYNS信号
VSYNC信号怎么同步到我们的代码的呢,Java 层接收 VSYNC 的入口是 dispatchVsync(),也就是说每当系统底层产生一个VSYNC信号,系统都会回调dispatchVsync()方法
// Called from native code. @SuppressWarnings("unused") private void dispatchVsync(long timestampNanos, int builtInDisplayId, int frame) { onVsync(timestampNanos, builtInDisplayId, frame); }
private final class FrameDisplayEventReceiver extends DisplayEventReceiver implements Runnable { private boolean mHavePendingVsync; private long mTimestampNanos; private int mFrame; public FrameDisplayEventReceiver(Looper looper, int vsyncSource) { super(looper, vsyncSource); } @Override public void onVsync(long timestampNanos, int builtInDisplayId, int frame) { ...... mTimestampNanos = timestampNanos; mFrame = frame; Message msg = Message.obtain(mHandler, this); msg.setAsynchronous(true); mHandler.sendMessageAtTime(msg, timestampNanos / TimeUtils.NANOS_PER_MS); } @Override public void run() { mHavePendingVsync = false; doFrame(mTimestampNanos, mFrame);
onVsync方法中,Message.obtain(mHandler, this) 所以 msg.callback 是 this,最后会调用到 msg.callback.run(),也就是 FrameDisplayEventReceiver run(),进入 doFrame() mTimestampNanos,它是来自 onVsync 的 timestampNanos 参数,代表产生 VSYNC 的时间。
void doFrame(long frameTimeNanos, int frame) { final long startNanos; synchronized (mLock) { if (!mFrameScheduled) { return; // no work to do } if (DEBUG_JANK && mDebugPrintNextFrameTimeDelta) { mDebugPrintNextFrameTimeDelta = false; Log.d(TAG, "Frame time delta: " + ((frameTimeNanos - mLastFrameTimeNanos) * 0.000001f) + " ms"); } long intendedFrameTimeNanos = frameTimeNanos; startNanos = System.nanoTime();//正真开始的时间 final long jitterNanos = startNanos - frameTimeNanos; if (jitterNanos >= mFrameIntervalNanos) { // 时间差除以每帧时间间隔,来计算丢掉了几帧。其中mFrameIntervalNanos = (long)(1000000000 / getRefreshRate());一般刷新率为60,时间间隔为16.6ms final long skippedFrames = jitterNanos / mFrameIntervalNanos; if (skippedFrames >= SKIPPED_FRAME_WARNING_LIMIT) { Log.i(TAG, "Skipped " + skippedFrames + " frames! " + "The application may be doing too much work on its main thread."); } // 取余数,作为帧偏移时间 final long lastFrameOffset = jitterNanos % mFrameIntervalNanos; if (DEBUG_JANK) { Log.d(TAG, "Missed vsync by " + (jitterNanos * 0.000001f) + " ms " + "which is more than the frame interval of " + (mFrameIntervalNanos * 0.000001f) + " ms! " + "Skipping " + skippedFrames + " frames and setting frame " + "time to " + (lastFrameOffset * 0.000001f) + " ms in the past."); } frameTimeNanos = startNanos - lastFrameOffset; } if (frameTimeNanos < mLastFrameTimeNanos) { if (DEBUG_JANK) { Log.d(TAG, "Frame time appears to be going backwards. May be due to a " + "previously skipped frame. Waiting for next vsync."); } scheduleVsyncLocked(); return; } mFrameInfo.setVsync(intendedFrameTimeNanos, frameTimeNanos); mFrameScheduled = false; mLastFrameTimeNanos = frameTimeNanos; } //执行对应的callBack try { Trace.traceBegin(Trace.TRACE_TAG_VIEW, "Choreographer#doFrame"); AnimationUtils.lockAnimationClock(frameTimeNanos / TimeUtils.NANOS_PER_MS); mFrameInfo.markInputHandlingStart(); doCallbacks(Choreographer.CALLBACK_INPUT, frameTimeNanos); mFrameInfo.markAnimationsStart(); doCallbacks(Choreographer.CALLBACK_ANIMATION, frameTimeNanos); mFrameInfo.markPerformTraversalsStart(); doCallbacks(Choreographer.CALLBACK_TRAVERSAL, frameTimeNanos); doCallbacks(Choreographer.CALLBACK_COMMIT, frameTimeNanos); } finally { AnimationUtils.unlockAnimationClock(); Trace.traceEnd(Trace.TRACE_TAG_VIEW); } if (DEBUG_FRAMES) { final long endNanos = System.nanoTime(); Log.d(TAG, "Frame " + frame + ": Finished, took " + (endNanos - startNanos) * 0.000001f + " ms, latency " + (startNanos - frameTimeNanos) * 0.000001f + " ms."); } }
如果你平时注意卡顿的日志信息,那么下面这个段log就不会陌生了
if (skippedFrames >= SKIPPED_FRAME_WARNING_LIMIT) { Log.i(TAG, "Skipped " + skippedFrames + " frames! " + "The application may be doing too much work on its main thread.");
SKIPPED_FRAME_WARNING_LIMIT的默认值是30,也就说当我们的程序卡顿大于30时会打印这条log信息 doFrame()方法最后调用doCallbacks()来处理用户输入,动画,绘制等UI操作。
void doCallbacks(int callbackType, long frameTimeNanos) { CallbackRecord callbacks; synchronized (mLock) { // We use "now" to determine when callbacks become due because it's possible // for earlier processing phases in a frame to post callbacks that should run // in a following phase, such as an input event that causes an animation to start. final long now = System.nanoTime(); callbacks = mCallbackQueues[callbackType].extractDueCallbacksLocked( now / TimeUtils.NANOS_PER_MS); if (callbacks == null) { return; } mCallbacksRunning = true; ...... try { Trace.traceBegin(Trace.TRACE_TAG_VIEW, CALLBACK_TRACE_TITLES[callbackType]); for (CallbackRecord c = callbacks; c != null; c = c.next) { if (DEBUG_FRAMES) { Log.d(TAG, "RunCallback: type=" + callbackType + ", action=" + c.action + ", token=" + c.token + ", latencyMillis=" + (SystemClock.uptimeMillis() - c.dueTime)); } c.run(frameTimeNanos); } } finally { synchronized (mLock) { mCallbacksRunning = false; do { final CallbackRecord next = callbacks.next; recycleCallbackLocked(callbacks); callbacks = next; } while (callbacks != null); } Trace.traceEnd(Trace.TRACE_TAG_VIEW); } }
extractDueCallbacksLocked 是取出执行时间在当前时间之前的所有 CallbackRecord,CallbackRecord 是一个链表,然后遍历 callbacks 执行 run 方法
private static final class CallbackRecord { public CallbackRecord next; public long dueTime; public Object action; // Runnable or FrameCallback public Object token; public void run(long frameTimeNanos) { if (token == FRAME_CALLBACK_TOKEN) { ((FrameCallback)action).doFrame(frameTimeNanos); } else { ((Runnable)action).run(); } } }
如果们通过postFrameCallback(FrameCallback)注册回调事件,下一次 Choreographer doFrame 时就会调用 FrameCallback.doFrame,还记得刚开始我们注册FrameCallback是系统为封装FrameCallback的类型吗 正是FRAME_CALLBACK_TOKEN,因此这里会走 ((FrameCallback)action).doFrame(frameTimeNanos);,为什么我们每次都需要注册一个下呢,这是因为每次“垂直同步”都会删除调用的注册事件。 如果这个CallbackRecord是view动画或绘制就会调用((Runnable)action).run();
下面是收到VSYNC的流程图
小结
- Choreographer是线程单例的,而且必须要和一个Looper绑定,因为其内部有一个Handler需要和Looper绑定。
- 首先我们通过postFrameCallback(FrameCallback callback)方法,最终通过native方法 nativeScheduleVsync(mReceiverPtr)和一个VSYNC绑定。
- 当下一次VSYNC信号来时,回调我们绑定的接口,然后统计两针之间的时间,判断是否掉帧
- 如果掉帧获取卡顿日志,继续监控下个VSYNC信号。