背景
我遇到一个很有意思的ANR问题，从trace分析来看，Launcher应用在不断地queuebuffer，但是SurfaceFlinger对应的buffer的数量没有增加，也就意味着buffer无法被消费，等到3个buffer都是用掉了，应用也就dequeuebuffer不出来了，虽然dequeuebuffer的timeout时间是4s小于anr的5s，但是还是有可能触发anr。
一、应用在不断地queuebuffer，但是SurfaceFlinger对应的buffer的数量没有增加
因为BlastBufferQueue被引入之后，queuebuffer之后，需要在调用Transaction的apply才能让SurfaceFlinger对应的buffer数量增加，才能被消费
void BLASTBufferQueue::acquireNextBufferLocked(
const std::optional<SurfaceComposerClient::Transaction*> transaction) {
....
t->setBuffer(mSurfaceControl, buffer, fence, bufferItem.mFrameNumber, releaseBufferCallback);
....
if (applyTransaction) {//情况一、常规的情况
// All transactions on our apply token are one-way. See comment on mAppliedLastTransaction
t->setApplyToken(mApplyToken).apply(false, true);//sf就会立马更新buffer的数量
mAppliedLastTransaction = true;
mLastAppliedFrameNumber = bufferItem.mFrameNumber;
} else {//情况二、特殊的情况
//sf不会立马更新，而是需要等sync机制，等所有窗口ready之后才能apply Transaction
t->setBufferHasBarrier(mSurfaceControl, mLastAppliedFrameNumber);
mAppliedLastTransaction = false;
}
}
很明显Trace中就是应该走了上面代码中情况二，我一开始怀疑是我之前[076]SHELL TRANSITIONS
这个文章中讲的BLASTSyncEngine机制导致了这个问题，然后我就尝试打开这个日志。
adb shell wm logging enable-text WM_DEBUG_SYNC_ENGINE
但是事实并不如人意，没有出现我预料中的WindowManager: SyncGroup的日志，然后我就继续跟代码，有没有别的机制可以也走情况二
二、反向跟代码
2.1 applyTransaction在什么情况下为false
2.1.1中首先acquireNextBufferLocked中transaction不为空，继续反推
2.1.2中syncTransactionSet为true，也就说mTransactionReadyCallback不为空
2.1.3中有人调用了syncNextTransaction最后设置了mTransactionReadyCallback。
frameworks/native/libs/gui/BLASTBufferQueue.cpp
//2.1.1
void BLASTBufferQueue::acquireNextBufferLocked(
const std::optional<SurfaceComposerClient::Transaction*> transaction) {
SurfaceComposerClient::Transaction localTransaction;
bool applyTransaction = true;
SurfaceComposerClient::Transaction* t = &localTransaction;
if (transaction) {//transaction不为空
t = *transaction;
applyTransaction = false;
}
}
//2.1.2
void BLASTBufferQueue::onFrameAvailable(const BufferItem& item) {
SurfaceComposerClient::Transaction* prevTransaction = nullptr;
{
BBQ_TRACE();
std::unique_lock _lock{mMutex};
const bool syncTransactionSet = mTransactionReadyCallback != nullptr;//mTransactionReadyCallback不为空
if (syncTransactionSet) {//syncTransactionSet为true
acquireNextBufferLocked(mSyncTransaction);
} else if (!mWaitForTransactionCallback) {
acquireNextBufferLocked(std::nullopt);
}
}
if (prevCallback) {
prevCallback(prevTransaction);
}
}
//2.1.3
void BLASTBufferQueue::syncNextTransaction(
std::function<void(SurfaceComposerClient::Transaction*)> callback,
bool acquireSingleBuffer) {
BBQ_TRACE();
mTransactionReadyCallback = callback;//设置了callback
}
3.2 谁会调用syncNextTransaction
因为出问题的是app，我不信他会直接调用BLASTBufferQueue.cpp的syncNextTransaction，肯定调用BLASTBufferQueue.java的syncNextTransaction
调用的流程如下：
BLASTBufferQueue.java.syncNextTransaction->
android_graphics_BLASTBufferQueue.cpp.nativeSyncNextTransaction->
BLASTBufferQueue.cpp.syncNextTransaction
frameworks/base/graphics/java/android/graphics/BLASTBufferQueue.java
public void syncNextTransaction(boolean acquireSingleBuffer,
Consumer<SurfaceControl.Transaction> callback) {
nativeSyncNextTransaction(mNativeObject, callback, acquireSingleBuffer);//跳转到3.2.1
}
public void syncNextTransaction(Consumer<SurfaceControl.Transaction> callback) {
syncNextTransaction(true /* acquireSingleBuffer */, callback);
}
frameworks/base/core/jni/android_graphics_BLASTBufferQueue.cpp
//3.2.1
static void nativeSyncNextTransaction(JNIEnv* env, jclass clazz, jlong ptr, jobject callback,
jboolean acquireSingleBuffer) {
sp<BLASTBufferQueue> queue = reinterpret_cast<BLASTBufferQueue*>(ptr);
JavaVM* vm = nullptr;
LOG_ALWAYS_FATAL_IF(env->GetJavaVM(&vm) != JNI_OK, "Unable to get Java VM");
if (!callback) {
queue->syncNextTransaction(nullptr, acquireSingleBuffer);
} else {
auto globalCallbackRef =
std::make_shared<JGlobalRefHolder>(vm, env->NewGlobalRef(callback));
queue->syncNextTransaction(
[globalCallbackRef](SurfaceComposerClient::Transaction* t) {
JNIEnv* env = getenv(globalCallbackRef->vm());
env->CallVoidMethod(globalCallbackRef->object(), gTransactionConsumer.accept,
env->NewObject(gTransactionClassInfo.clazz,
gTransactionClassInfo.ctor,
reinterpret_cast<jlong>(t)));
},
acquireSingleBuffer);
}
}
接下来那就搜源码中所有调用BLASTBufferQueue.java的syncNextTransaction的代码，好在结果不多，凭借我十年的工作经验，继续跟registerCallbacksForSync
2.3 onReadyToSync最终触发了syncNextTransaction
继续反推代码
2.3.1中syncBuffer和syncBufferCallback不为空
2.3.2中mSyncBufferCallback是不为空的
2.3.3和2.3.4中SurfaceSyncer.SyncTarget将会调用onReadyToSync然后设置mSyncBufferCallback ，接下来就看谁调用了onReadyToSync。
我准备用这条神奇日志来跟踪，因为继续反向跟太累了
Log.v("kobewang", "onReadyToSync", new Exception("kobewang"));
frameworks/base/core/java/android/view/ViewRootImpl.java
//2.3.1
private void registerCallbacksForSync(boolean syncBuffer,
final SurfaceSyncer.SyncBufferCallback syncBufferCallback) {
mAttachInfo.mThreadedRenderer.registerRtFrameCallback(new FrameDrawingCallback() {
@Override
public void onFrameDraw(long frame) {
}
@Override
public HardwareRenderer.FrameCommitCallback onFrameDraw(int syncResult, long frame) {
//开始绘制的时候设置syncBufferCallback
if (syncBuffer) {
mBlastBufferQueue.syncNextTransaction(syncBufferCallback::onBufferReady);
}
}
}
}
//2.3.2
private boolean performDraw() {
boolean usingAsyncReport = isHardwareEnabled() && mSyncBufferCallback != null;//mSyncBufferCallback不为空
if (usingAsyncReport) {
registerCallbacksForSync(mSyncBuffer, mSyncBufferCallback);
} else if (mHasPendingTransactions) {
}
}
//2.3.3
private void readyToSync(SurfaceSyncer.SyncBufferCallback syncBufferCallback) {
mSyncBufferCallback = syncBufferCallback;
}
//2.3.4
public final SurfaceSyncer.SyncTarget mSyncTarget = new SurfaceSyncer.SyncTarget() {
@Override
public void onReadyToSync(SurfaceSyncer.SyncBufferCallback syncBufferCallback) {
Log.v("kobewang", "onReadyToSync", new Exception("kobewang"));//我添加了一个日志
readyToSync(syncBufferCallback);//最后设置了syncBufferCallback
}
@Override
public void onSyncComplete() {
mHandler.postAtFrontOfQueue(() -> {
if (--mNumSyncsInProgress == 0 && mAttachInfo.mThreadedRenderer != null) {
HardwareRenderer.setRtAnimationsEnabled(true);
}
});
}
};
2.4 神奇的日志发挥了神奇的作用
堆栈中的行数可能对应不上，因为我屏蔽了一些我们公司的代码，我用AOSP的代码来表达意思
12-07 17:57:29.435 8956 8956 V kobewang: onReadyToSync
12-07 17:57:29.435 8956 8956 V kobewang: java.lang.Exception: kobewang
12-07 17:57:29.435 8956 8956 V kobewang: at android.view.ViewRootImpl$9.onReadyToSync(ViewRootImpl.java:11501)
12-07 17:57:29.435 8956 8956 V kobewang: at android.window.SurfaceSyncer$SyncSet.addSyncableSurface(SurfaceSyncer.java:352)
12-07 17:57:29.435 8956 8956 V kobewang: at android.window.SurfaceSyncer.addToSync(SurfaceSyncer.java:231)
12-07 17:57:29.435 8956 8956 V kobewang: at android.window.SurfaceSyncer.addToSync(SurfaceSyncer.java:210)
12-07 17:57:29.435 8956 8956 V kobewang: at com.android.systemui.animation.ViewRootSync.synchronizeNextDraw(ViewRootSync.kt:7)
12-07 17:57:29.435 8956 8956 V kobewang: at com.android.systemui.animation.ViewRootSync.synchronizeNextDraw(ViewRootSync.kt:11)
12-07 17:57:29.435 8956 8956 V kobewang: at com.android.launcher3.taskbar.TaskbarLauncherStateController.onIconAlignmentRatioChanged(TaskbarLauncherStateController.java:88)
最关键的代码onIconAlignmentRatioChanged，很明显Launcher希望mLauncher.getHotseat()和mControllers.taskbarActivityContext.getDragLayer()这两个View在下一帧同时显示，利用的机制就是SurfaceSyncer。
private void onIconAlignmentRatioChanged(Supplier<Float> alignmentSupplier) {
// Sync the first frame where we swap taskbar and hotseat.
if (firstFrameVisChanged && mCanSyncViews && !Utilities.IS_RUNNING_IN_TEST_HARNESS) {
ViewRootSync.synchronizeNextDraw(mLauncher.getHotseat(),
mControllers.taskbarActivityContext.getDragLayer(),
() -> {});
}
}
frameworks/base/packages/SystemUI/animation/src/com/android/systemui/animation/ViewRootSync.kt
object ViewRootSync {
private var surfaceSyncer: SurfaceSyncer? = null
/**
* Synchronize the next draw between the view roots of [view] and [otherView], then run [then].
*
* Note that in some cases, the synchronization might not be possible (e.g. WM consumed the
* next transactions) or disabled (temporarily, on low ram devices). In this case, [then] will
* be called without synchronizing.
*/
fun synchronizeNextDraw(
view: View,
otherView: View,
then: () -> Unit
) {
if (!view.isAttachedToWindow || view.viewRootImpl == null ||
!otherView.isAttachedToWindow || otherView.viewRootImpl == null ||
view.viewRootImpl == otherView.viewRootImpl) {
// No need to synchronize if either the touch surface or dialog view is not attached
// to a window.
then()
return
}
surfaceSyncer = SurfaceSyncer().apply {
val syncId = setupSync(Runnable { then() })
addToSync(syncId, view)
addToSync(syncId, otherView)
markSyncReady(syncId)
}//利用SurfaceSyncer实现两个view的同一帧显示
}
/**
* A Java-friendly API for [synchronizeNextDraw].
*/
@JvmStatic
fun synchronizeNextDraw(view: View, otherView: View, then: Runnable) {
synchronizeNextDraw(view, otherView, then::run)
}
}
mLauncher.getHotseat()就是最开头背景中trace中dequeue timeout窗口，mControllers.taskbarActivityContext.getDragLayer()就是对应Taskbar，所以目前来看问题就出在了为什么Taskbar没有完成绘制。
三、为什么Taskbar没有完成绘制
当我把Taskbar也加进来的时候，和Launcher的主线程加进来，真相大白，原来某个service stop导致了原来Taskbar被销毁了。
现场还原
一开始调用以下代码希望trace中mLauncher.getHotseat()其实就是QuickstepLauncher与Taskbar利用SurfaceSyncer的功能进行同步显示。
ViewRootSync.synchronizeNextDraw(mLauncher.getHotseat(),
mControllers.taskbarActivityContext.getDragLayer(),
() -> {});
虽然有一定的窗口销毁的判断。
if (!view.isAttachedToWindow || view.viewRootImpl == null ||
!otherView.isAttachedToWindow || otherView.viewRootImpl == null ||
view.viewRootImpl == otherView.viewRootImpl) {
// No need to synchronize if either the touch surface or dialog view is not attached
// to a window.
then()
return
}
但是窗口销毁恰好发生在这个判断之后，所以等mLauncher.getHotseat()绘制完了，Taskbar因为窗口被销毁了，导致没有绘制完，最终导致了mLauncher.getHotseat()一直在等旧的Taskbar绘制完成，这怎么可能还等的到呢。
四、SurfaceSyncer连这种情况就没有考虑到嘛？
一开始我还觉得不可能google工程师没有考虑到这个问题，但是我看了SurfaceSyncer的代码，的确发现SurfaceSyncer就是没考虑这种情况。
当时我和同事沟通就觉得，应该有个timeout机制，例如1s以后需要同步显示的Surface其中一个没有绘制完成，剩下的Surface对应的Transation就应该apply出去。
4.1 相同的app在android 14上会界面卡，但是不会anr
新的线索，然后我去看android 14的代码，结果发现SurfaceSyncer已经被SurfaceSyncGroup代替了，然后我就凭直觉搜了timeout，果然命中。
一旦timeout触发，就会调用4.1.1中runnable的代码， mPendingSyncs.clear()之后调用4.1.2的markSyncReady，然后调用4.1.3中checkIfSyncIsComplete，最后调用4.1.4中transaction.apply()，这样子就可以解决问题中这种情况。
frameworks/base/core/java/android/window/SurfaceSyncGroup.java
public static final int TRANSACTION_READY_TIMEOUT = 1000 * Build.HW_TIMEOUT_MULTIPLIER;
//4.1.1
private void addTimeout() {
Looper looper = null;
synchronized (sHandlerThreadLock) {
if (sHandlerThread == null) {
sHandlerThread = new HandlerThread("SurfaceSyncGroupTimer");
sHandlerThread.start();
}
looper = sHandlerThread.getLooper();
}
synchronized (mLock) {
if (mTimeoutAdded || mTimeoutDisabled || looper == null) {
// We only need one timeout for the entire SurfaceSyncGroup since we just want to
// ensure it doesn't stay stuck forever.
return;
}
if (mHandler == null) {
mHandler = new Handler(looper);
}
mTimeoutAdded = true;
}
Runnable runnable = () -> {
Log.e(TAG, "Failed to receive transaction ready in " + TRANSACTION_READY_TIMEOUT
+ "ms. Marking SurfaceSyncGroup(" + mName + ") as ready");
// Clear out any pending syncs in case the other syncs can't complete or timeout due to
// a crash.
synchronized (mLock) {
mPendingSyncs.clear();//timeout时间到了就把mPendingSyncs清空
}
markSyncReady();//重新触发sync的确认，因为mPendingSyncs已经为空了，就可以触发
};
mHandler.postDelayed(runnable, this, TRANSACTION_READY_TIMEOUT);
}
//4.1.2
public void markSyncReady() {
if (DEBUG) {
Log.d(TAG, "markSyncReady " + mName);
}
if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
Trace.instantForTrack(Trace.TRACE_TAG_VIEW, mTrackName, "markSyncReady");
}
synchronized (mLock) {
if (mHasWMSync) {
try {
WindowManagerGlobal.getWindowManagerService().markSurfaceSyncGroupReady(mToken);
} catch (RemoteException e) {
}
}
mSyncReady = true;
checkIfSyncIsComplete();//确认是否已经sync ready
}
}
//4.1.3
private void checkIfSyncIsComplete() {
if (mFinished) {
if (DEBUG) {
Log.d(TAG, "SurfaceSyncGroup=" + mName + " is already complete");
}
mTransaction.apply();
return;
}
if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
Trace.instantForTrack(Trace.TRACE_TAG_VIEW, mTrackName,
"checkIfSyncIsComplete mSyncReady=" + mSyncReady
+ " mPendingSyncs=" + mPendingSyncs.size());
}
if (!mSyncReady || !mPendingSyncs.isEmpty()) { //mPendingSyncs.isEmpty()为true
if (DEBUG) {
Log.d(TAG, "SurfaceSyncGroup=" + mName + " is not complete. mSyncReady="
+ mSyncReady + " mPendingSyncs=" + mPendingSyncs.size());
}
return;
}
if (DEBUG) {
Log.d(TAG, "Successfully finished sync id=" + mName);
}
mTransactionReadyConsumer.accept(mTransaction);//这里就会apply了
mFinished = true;
if (mTimeoutAdded) {
mHandler.removeCallbacksAndMessages(this);
}
}
//4.1.4
mTransactionReadyConsumer = (transaction) -> {
if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
Trace.asyncTraceForTrackBegin(Trace.TRACE_TAG_VIEW, mTrackName,
"Invoke transactionReadyCallback="
+ transactionReadyCallback.hashCode(), hashCode());
}
lastCallback.accept(null);
try {
transactionReadyCallback.onTransactionReady(transaction);
} catch (RemoteException e) {
transaction.apply();//这里就会apply了
}
if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
Trace.asyncTraceForTrackEnd(Trace.TRACE_TAG_VIEW, mTrackName, hashCode());
}
};
五、总结
回到问题的最开始，现在你觉得这个bug是系统的问题还是应用的问题，可能觉得多数情况下，这类问题就是应用组和系统组之间互相扯皮。
应用组：为什么14是好的，13有问题。
系统组：为什么就你Launcher有问题，别的应用没问题。
谁都不愿意仔细去分析，运气好呢，可能这个bug在别的改动下影响service stop的时机，导致无法复现这个问题，最后就不了了之了。
如果说[011]一个看似是系统问题的应用问题的解决过程这个问题是多年学习Binder之后的体现，那这个问题就是我多年学习整个Android显示框架之后的体现，整个过程，其实我没有拿到出问题的机器，只能让同事帮忙加日志，抓trace，自己在跟踪代码分析，整个分析过程并没有文章中的那么顺畅，也走了很多岔路，其实这个问题在一年前别项目已经报出过了，但是由于当时无法找到必现路径，而且当时这问题也没到我头上分析，一直没有找到root cause，这次总算把这个问题根因找到了，很开心，从中也学到了很多东西。
尾巴
最后同事问我有没有整体的一个刷新流程图，从input事件到显示的教程，以及看Trace的技巧，我真的很难回答这个问题，我只能让他去看我的B站视频以及https://www.androidperformance.com/中介绍的trace的技巧，但是事实上就算看过了，去解决实际问题的时候，任何一个知识点的欠缺就需要你去补，养兵千日，用在一时，知识学习也是一样，平时不断地积累，然后工作中不断对已经学习知识点深入理解，巩固，最后才能不断地进步。
