【Android原生问题分析】夸克、抖音划动无响应问题【Android14】
1 问题描述
偶现问题，用户打开夸克、抖音后，在界面上划动无响应，但是没有ANR。回到Launcher后再次打开夸克/抖音，发现App的界面发生了变化，但是仍然是划不动的。
2 log初分析
复现问题附近的log为：
用户打开夸克的时间点为“00:27:25”左右，然后是持续的划动无响应，最后在“00:27:36”最后退出了夸克。
现在基本上已经没有冻屏的操作了，从log中也没有看到可能的痕迹，并且根据用户的描述，在夸克界面上划动无响应，切换到别的界面后再切回夸克，看到夸克的界面是有更新的，说明应该是在绘制或者合成的地方卡住了。
由于默认的log有限，无法定位到具体的问题，因此需要添加log。
3 第一次添加log
由于不确定是哪个阶段出了问题，因此先针对Input流程和measure、layout以及draw流程添加了log，后面测试再次复现问题后，查看log发现问题出在draw流程（其实从问题描述上也能看出来，从App切换到Launcher再切换回App，界面发生了变化，说明输入事件应该是被App正确接收到了）。
第一帧正常：
从第二帧开始异常：
异常的点在ViewRootImpl.performDraw：
这里就是问题的直接原因了，明明是亮屏状态，但是ViewRootImpl.mAttachInfo.mDisplayState保存的值却是Display.STATE_OFF，导致代码误判断此时处于灭屏状态，因此不会继续走绘制流程。
至于为什么第一帧有没问题，而从第二帧开始就出问题了，因为第一帧的时候，ViewRootImpl.mReportNextDraw为true，所以没有提前return，可以继续走draw流程。而从第二帧开始，ViewRootImpl.mReportNextDraw就变成了false，导致代码提前返回。
搜索代码，AttachInfo.mDisplayState赋值的地方只有四处：
1、View.dispatchMovedToDisplay
2、ViewRootImpl.onMovedToDisplay
3、ViewRootImpl.setView
4、ViewRootImpl.mDisplayListener.onDisplayChanged
前两处是跟移动到新的Display相关的，可以排除，第3处是窗口首次添加，也可以排除，那么就只有第4处是Display状态改变后，更新AttachInfo.mDisplayState的地方。
另外根据本地调试也的确如此，当发生亮灭屏时，触发的是ViewRootImpl.mDisplayListener.onDisplayChanged：
DisplayManagerGlobal.DisplayManagerCallback.onDisplayEvent
-> DisplayManagerGlobal.handleDisplayEvent
-> DisplayManagerGlobal.DisplayListenerDelegate.sendDisplayEvent
最终的调用起点在系统进程的DisplayManagerService。
由于之前对DisplayManagerService了解比较少，所以还不清楚问题出在哪儿，这次加的log不太够，需要继续在DisplayManagerService处加log，然后让测试帮忙去复现问题。
但是同时别的同事也合入了几个google的patch，导致后续问题复现不到了，这个问题一度没有了下文，当时觉得还挺可惜，花了挺长的时间去分析，结果后面复现不到了。
4 第二次添加log
虽然之前的问题不了了之了，但是后面别的项目又继续复现了该问题，希望又被点燃了…先在DisplayManagerService中添加一些log，然后继续让测试同事帮忙复现，最终成功复现到了问题。
以下是当时的log分析：
4.1 11-12 22:25:14 - 第一次启动抖音
：
这个是后续发生问题的抖音界面第一次启动的时间，此时是正常的。
中间又多次启动抖音以及亮灭屏，但是都没有问题，所以我们跳过这些阶段。
直接看发生问题前的那次启动抖音的情况。
4.2 11-13 10:33:39 - 再次启动抖音
ViewRootImpl保存的DisplayState已经是2了，即Display.STATE_ON，这次绘制没有问题。
4.3 11-13 10:53:42 - 灭屏
此次DisplayManagerService向SplashActivity对应进程“17885”进行了通知。
最终抖音对应进程“17885”也打印了相应的onDisplayChanged的log。
4.4 11-13 10:55:07 - 亮屏
DisplayManagerService没有通知抖音对应进程“17885”，有以下log打印：
11-13 10:55:07.252351 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.252761 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.253925 1450 1575 D DisplayManagerService: Ignore redundant display event 0/2 to 10224/16998
11-13 10:55:07.253967 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.253978 1450 1575 D DisplayManagerService: Ignore redundant display event 0/2 to 10224/16998
4.5 11-13 10:55:16 - 灭屏
DisplayManagerService没有通知抖音对应进程“17885”。
4.6 11-13 13:00:00 - 出现问题前的最后一次亮屏
DisplayManagerService还是没有通知抖音对应进程“17885”。
4.7 11-13 13:24:18 - 再次启动抖音，有问题
原因则是“11-13 10:53:42”那次灭屏DisplayManagerService通知到了抖音对应进程“17885”，随后不管是亮屏还是灭屏都没有再通知抖音进程，导致此次启动抖音SplashActivity后，其ViewRootImpl处保存的DisplayState还是1，即Display.STATE_OFF，灭屏状态，所以不会走绘制流程。
接下来需要看下具体的代码，为什么没有通知到抖音进程，并且打印了这些log：
11-13 10:55:07.252351 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.252761 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.253925 1450 1575 D DisplayManagerService: Ignore redundant display event 0/2 to 10224/16998
11-13 10:55:07.253967 1450 1575 I DisplayManagerService: DisplayManagerService.deliverDisplayEvent: isUidCached=10224
11-13 10:55:07.253978 1450 1575 D DisplayManagerService: Ignore redundant display event 0/2 to 10224/16998
5 代码分析
5.1 App侧注册display状态的监听
ViewRootImpl有一个DisplayListener的成员变量mDisplayListener，该成员变量用来接收DisplayManagerService关于Display状态改变的通知：
当onDisplayChanged回调触发，会更新mAttachInfo.mDisplayState的值。
该成员变量通过DisplayManagerGlobal.registerDisplayListener进行注册，最终是调用了IDisplayManager.registerCallbackWithEventMask，跨进程在DisplayManagerService进行了注册，如下图：
DisplayManagerService内部类BinderService是IDisplayManager的本地实现，然后BinderService.registerCallbackWithEventMask又调用了DisplayManagerService.registerCallbackInternal：
最终，DisplayManagerService为每一个通过IDisplayManager.registerCallbackWithEventMask监听Display状态的客户端，都创建了一个CallbackRecord对象，用来代表一个客户端记录，该CallbackRecord被保存在DisplayManagerService的成员变量mCallbacks中。
至于CallbackRecord，其内部保存了客户端的pid和uid，因此可以唯一对应一个客户端。
5.2 DisplayManagerService通知客户端Display状态改变
直接放结论，在CallbackRecord.notifyDisplayEventAsync中：
CallbackRecord中的IDisplayManagerCallback类型的成员变量mCallback保存的是客户端进程传过来的IDisplayManagerCallback代理，因此调用IDisplayManagerCallback.onDisplayEvent最终可以调用到客户端进程的DisplayManagerGlobal：
最终通知到ViewRootImpl。
CallbackRecord.notifyDisplayEventAsync方法调用的地方有两处，先看第一处，在DisplayManagerService.deliverDisplayEvent：
这里会将DisplayManagerService.mCallbacks的数据拷贝到DisplayManagerService.mTempCallbacks，然后调用DisplayManagerService.isUidCached方法来判断需要通知的进程是否处于cached mode：
如果不是，那么说明此时该客户端进程的优先级比较高，需要直接调用CallbackRecord.notifyDisplayEventAsync来通知客户端Display状态改变的消息。
如果客户端进程处于cached mode，那么说明该进程处于一个优先级较低的状态，因此不会立即调用CallbackRecord.notifyDisplayEventAsync，而是创建一个PendingCallback对象，然后保存到DisplayManagerService的mPendingCallbackSelfLocked成员变量中，注意这里mPendingCallbackSelfLocked是根据uid去区分的，并非是pid。
等到客户端进程的进程优先级提高后，再去从DisplayManagerService.mPendingCallbackSelfLocked中取出相应的CallbackRecord，然后调用CallbackRecord.notifyDisplayEventAsync方法通知客户端进程，这也就是第二处调用CallbackRecord.notifyDisplayEventAsync的地方，在PendingCallback.sendPendingDisplayEvent：
而PendingCallback.sendPendingDisplayEvent方法则由UidImportanceListener.onUidImportance方法调用。
这里的逻辑很好理解，当进程的优先级改变的时候，会回调UidImportanceListener.onUidImportance，然后UidImportanceListener.onUidImportance中继续判断该进程的优先级，如果优先级高于IMPORTANCE_CACHED，那么会继续根据该进程的uid从DisplayManagerService.mPendingCallbackSelfLocked中找其对应的PendingCallback，如果能找到，那么调用PendingCallback.sendPendingDisplayEvent，最终在PendingCallback.sendPendingDisplayEvent中调用CallbackRecord.notifyDisplayEventAsync来通知客户端Display状态的改变。
5.3 省流版
概括一点说，就是并不是每次Display状态发生变化的时候，DisplayMangerService就会去通知抖音进程，而是会调用DisplayManagerService.isUidCached方法来看这个App进程的优先级是否足够高：
1）、如果优先级高于IMPORTANCE_CACHED，说明此时优先级还是挺高的，那么DisplayManagerService会立即通知抖音进程。
2）、如果优先级等于或者低于IMPORTANCE_CACHED，说明优先级不够高，那么DisplayManagerService不会立即通知抖音进程，而是为其创建一个记录，等到抖音进程的优先级改变并且高于IMPORTANCE_CACHED的时候，根据这个记录找到抖音进程，然后通知它。
6 原因分析
1）、首先是这次：”11-13 10:33:39 - 再次启动抖音“
这是离问题发生时间点最近的那次启动抖音。
2）、然后接着：”11-13 10:53:42 - 灭屏“
看到这次灭屏的时候，可能是由于距离启动抖音的时间不长，因此这时抖音进程的优先级还比较高，所以这次灭屏的时候，通知到了抖音进程17885。
3）、接着是”11-13 10:55:07 - 亮屏“
这里我们之前的分析有误，看了代码后才了解，不是说DisplayManagerService没有通知抖音进程17885，而是抖音进程的优先级比较低，所以没有立即通知抖音进程，而是为其创建了PendingCallback，等待抖音进程优先级提高后，再去通知抖音进程，如这里的log：
但是这里的逻辑有问题。
如log中显示的，这里抖音App的uid为10224，有三个进程，16998，17885，18213，我们关注的抖音的”SplashActivity”所在进程是17885.
然后再看代码：
首先对于抖音进程16998，由于这是遍历到的抖音的第一个进程，因此DisplayManagerService.mPendingCallbackSelfLocked中是没有抖音uid的信息的，所以这里会基于进程16998对应的CallbackRecord创建一个PendingCallback对象，然后保存到DisplayManagerService.mPendingCallbackSelfLocked中。
然后遍历到抖音进程17885的时候，由于它和抖音进程16998的uid是一样的，都是10224，那么这里就不会为进程17885再去创建一个PendingCallback对象， 而是直接复用上一步创建的那个PendingCallback，如这里的log打印：
”Ignore redundant display event…“
那么这里就是问题的根因所在了，抖音有三个进程，这里只为抖音进程16998对应的CallbackRecord创建了一个PendingCallback，到后续抖音进程优先级提高的时候，那么也只会调用该PendingCallback中的CallbackRecord的notifyDisplayEventAsync方法，那么这意味着只有进程16998会得到Display状态改变的通知，进程17885和进程18213都无法得到通知，再看后面抖音进程优先级提升的情况：
看到果然只有进程16998得到通知了，我们关注的进程17885没有被通知到，那么进程17885的ViewRootImpl保存的mAttachInfo.mDisplayState将一直是灭屏的状态。
不太省流的省流版
目前的代码，在一个App对应一个uid，以及一个pid的情况下，是够用的，但是实际上一个App对应了一个uid，但是可能会有多个进程，即一个uid会对应多个pid。
再回看我们的代码总结：如果App优先级等于或者低于IMPORTANCE_CACHED，说明优先级不够高，那么DisplayManagerService不会立即通知抖音进程，而是为其创建一个记录，等到抖音进程的优先级改变并且高于IMPORTANCE_CACHED的时候，根据这个记录找到抖音进程，然后通知它。
这里创建的记录，是根据uid去创建的，那么即使抖音有多个进程，也只会创建一个记录，根据遍历顺序来看则是pid最小的那个。
再看问题场景：
1）、启动完抖音后灭屏，此时抖音的优先级比较高，因此DisplayMangerService会立即通知抖音进程，这里抖音的三个进程都能通知到，因此进程17885的ViewRootImpl处保存的Display状态就是灭屏状态。
2）、过了一阵子再次亮屏，由于抖音的优先级降低了，所以DisplayManagerService没有立即通知抖音进程，而是创建为抖音创建了一个记录，等到抖音优先级提高的时候，再去通知抖音进程。此时抖音有三个进程，16998，17885，18213，这里只为pid最小的16998创建了一项纪录。
3）、后续抖音优先级提高的时候，DisplayMangerService只通知了进程16998，由于没有为剩下的两个进程创建记录，因此这两个进程就通知不到了，所以我们关注的进程17885出了问题。
从以上分析可以知道，我们需要为每一个pid都创建一个记录，而非每一个uid。
7 问题解决
最终看到已经有google patch解决这个问题了：
Diff - f2daa46634f6a1e5e329041f07a27dbc894d71b2^! - platform/frameworks/base - Git at Google
Correct the deferred sending of display events.
When multiple processes sharing the same uid become non-cached, the
current deferred transmission logic does not consider all of them,
leading to only the first process in the callback list to receive the
pending display events. Moreover, this first process may inadvertently
receive unintended display events.
Bug: 325692442
Test: manual, see bug description
Change-Id: Ife98a8d843a3000294fbc9929bb78a755534b5dc
Signed-off-by: Hyeongseop Shim <hyeongseop.shim@samsung.corp-partner.google.com>
diff --git a/services/core/java/com/android/server/display/DisplayManagerService.java b/services/core/java/com/android/server/display/DisplayManagerService.java
index ba21a32..434985e 100644
--- a/services/core/java/com/android/server/display/DisplayManagerService.java
+++ b/services/core/java/com/android/server/display/DisplayManagerService.java
@@ -464,10 +464,11 @@
// May be used outside of the lock but only on the handler thread.
private final ArrayList<CallbackRecord> mTempCallbacks = new ArrayList<CallbackRecord>();
- // Pending callback records indexed by calling process uid.
+ // Pending callback records indexed by calling process uid and pid.
// Must be used outside of the lock mSyncRoot and should be selflocked.
@GuardedBy("mPendingCallbackSelfLocked")
- public final SparseArray<PendingCallback> mPendingCallbackSelfLocked = new SparseArray<>();
+ public final SparseArray<SparseArray<PendingCallback>> mPendingCallbackSelfLocked =
+ new SparseArray<>();
// Temporary viewports, used when sending new viewport information to the
// input system. May be used outside of the lock but only on the handler thread.
@@ -1011,8 +1012,8 @@
}
// Do we care about this uid?
- PendingCallback pendingCallback = mPendingCallbackSelfLocked.get(uid);
- if (pendingCallback == null) {
+ SparseArray<PendingCallback> pendingCallbacks = mPendingCallbackSelfLocked.get(uid);
+ if (pendingCallbacks == null) {
return;
}
@@ -1020,7 +1021,12 @@
if (DEBUG) {
Slog.d(TAG, "Uid " + uid + " becomes " + importance);
}
- pendingCallback.sendPendingDisplayEvent();
+ for (int i = 0; i < pendingCallbacks.size(); i++) {
+ PendingCallback pendingCallback = pendingCallbacks.valueAt(i);
+ if (pendingCallback != null) {
+ pendingCallback.sendPendingDisplayEvent();
+ }
+ }
mPendingCallbackSelfLocked.delete(uid);
}
}
@@ -3193,16 +3199,23 @@
for (int i = 0; i < mTempCallbacks.size(); i++) {
CallbackRecord callbackRecord = mTempCallbacks.get(i);
final int uid = callbackRecord.mUid;
+ final int pid = callbackRecord.mPid;
if (isUidCached(uid)) {
// For cached apps, save the pending event until it becomes non-cached
synchronized (mPendingCallbackSelfLocked) {
- PendingCallback pendingCallback = mPendingCallbackSelfLocked.get(uid);
+ SparseArray<PendingCallback> pendingCallbacks = mPendingCallbackSelfLocked.get(
+ uid);
if (extraLogging(callbackRecord.mPackageName)) {
- Slog.i(TAG,
- "Uid is cached: " + uid + ", pendingCallback: " + pendingCallback);
+ Slog.i(TAG, "Uid is cached: " + uid
+ + ", pendingCallbacks: " + pendingCallbacks);
}
+ if (pendingCallbacks == null) {
+ pendingCallbacks = new SparseArray<>();
+ mPendingCallbackSelfLocked.put(uid, pendingCallbacks);
+ }
+ PendingCallback pendingCallback = pendingCallbacks.get(pid);
if (pendingCallback == null) {
- mPendingCallbackSelfLocked.put(uid,
+ pendingCallbacks.put(pid,
new PendingCallback(callbackRecord, displayId, event));
} else {
pendingCallback.addDisplayEvent(displayId, event);
看注释，说的就是多个进程共享同一个uid的情况。
再看修改，将原来的：
public final SparseArray<PendingCallback> mPendingCallbackSelfLocked = new SparseArray<>();
改为了：
public final SparseArray<SparseArray<PendingCallback>> mPendingCallbackSelfLocked =
new SparseArray<>();
很明显，之前是一个uid对应一个PendingCallback对象，现在是一个uid对应一组PendingCallback对象，即一个uid对应多个进程的情况，这样同一个uid下多个进程都能得到通知了，代码比较简单，不再赘述。