[093]SurfaceSyncer的致命缺陷

作者: 王小二的技术栈 | 来源:发表于2023-12-07 12:51 被阅读0次

背景

我遇到一个很有意思的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的技巧，但是事实上就算看过了，去解决实际问题的时候，任何一个知识点的欠缺就需要你去补，养兵千日，用在一时，知识学习也是一样，平时不断地积累，然后工作中不断对已经学习知识点深入理解，巩固，最后才能不断地进步。

[093]SurfaceSyncer的致命缺陷

背景

一、应用在不断地queuebuffer，但是SurfaceFlinger对应的buffer的数量没有增加

二、反向跟代码

2.1 applyTransaction在什么情况下为false

3.2 谁会调用syncNextTransaction

2.3 onReadyToSync最终触发了syncNextTransaction

我准备用这条神奇日志来跟踪，因为继续反向跟太累了

2.4 神奇的日志发挥了神奇的作用

三、为什么Taskbar没有完成绘制

现场还原

四、SurfaceSyncer连这种情况就没有考虑到嘛？

4.1 相同的app在android 14上会界面卡，但是不会anr

五、总结

尾巴

相关文章

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读