CTS問題分析8

CTS/GTS問題分析8

今天發(fā)現(xiàn)一個初始設(shè)置錯誤可能導(dǎo)致的CTS問題，進(jìn)行下記錄

問題初探

測試命令： run cts -m CtsServicesHostTestCases -t android.server.cts.ActivityManagerDockedStackTests#testDockedStackToMinimizeWhenUnlocked

在host log中報(bào)錯如下:

junit.framework.AssertionFailedError
at junit.framework.Assert.fail(Assert.java:55)
at junit.framework.Assert.assertTrue(Assert.java:22)
at junit.framework.Assert.assertTrue(Assert.java:31)
at junit.framework.TestCase.assertTrue(TestCase.java:201)
at android.server.cts.ActivityManagerDockedStackTests.assertDockMinimized(ActivityManagerDockedStackTests.java:559)
at android.server.cts.ActivityManagerDockedStackTests.testDockedStackToMinimizeWhenUnlocked(ActivityManagerDockedStackTests.java:438)

case的大致流程是：

啟動TestActivity，將TestActivity放到stack 3，滅屏，重新點(diǎn)亮屏幕，觀察當(dāng)前window狀態(tài) (dumpsys window -a ) ，若mMinimizedDock = true，則case pass，否則fail

看了下bugreport中的event log，如下：

10-23 21:41:13.636 1000 1523 1523 I screen_toggled: 1
10-23 21:41:13.636 1000 1523 1523 I power_screen_broadcast_send: 1
10-23 21:41:13.637 1000 1523 1629 I am_set_resumed_activity: [0,android.server.cts/.TestActivity,resumeTopActivityInnerLocked]
10-23 21:41:13.640 1000 1523 1629 I am_resume_activity: [9521,113644122,55,android.server.cts/.TestActivity]
10-23 21:41:13.678 10157 9521 9521 I am_on_resume_called: [0,android.server.cts.TestActivity,RESUME_ACTIVITY]
10-23 21:41:13.682 1000 1523 1611 I am_pss : [6167,10012,com.android.defcontainer,4247552,3424256,0]
10-23 21:41:13.714 1000 1523 1523 I power_screen_broadcast_done: [1,78,1]
10-23 21:41:13.825 1000 1523 1629 I sysui_multi_action: [757,198,758,1,759,0,793,205]
10-23 21:41:13.825 1000 1523 1629 I power_screen_state: [1,0,0,0,205]
10-23 21:41:14.319 1000 1523 2988 I am_uid_stopped: 10157
10-23 21:41:14.319 1000 1523 2988 I am_kill : [0,9521,android.server.cts,0,stop android.server.cts: from process:9660]
10-23 21:41:14.321 1000 1523 2988 I am_finish_activity: [0,113644122,55,android.server.cts/.TestActivity,proc died without state saved]

重新亮屏?xí)r并沒有發(fā)現(xiàn)異常的event log，說明就是mMinimizedDock這個值為false導(dǎo)致的錯誤，先轉(zhuǎn)給分屏看了下，發(fā)現(xiàn)關(guān)閉Skip Screen lock測試即可通過；因此分屏沒有繼續(xù)看下去，但是這其實(shí)是不符合正常的CTS測試設(shè)置的，因此還是有繼續(xù)調(diào)研的必要。

問題分析

發(fā)現(xiàn)mMinimizedDock這個值可以等價(jià)于DividerView的mDockedStackMinimized屬性，DividerView是分屏?xí)r中間的分割符，這樣就可以將問題定位到DividerView的變化，其是由DockedStackDividerController控制的；因此，我們在其中的notifyDockedStackMinimizedChanged中打出調(diào)用棧

private void notifyDockedStackMinimizedChanged(boolean minimizedDock, boolean animate,
        boolean isHomeStackResizable) {
 
    RuntimeException e1 = new RuntimeException();
    e1.fillInStackTrace();
    e1.printStackTrace();
    ...
}

然后重新打包復(fù)現(xiàn)，可以發(fā)現(xiàn)如下log:

手機(jī)滅屏?xí)r關(guān)鍵log:

10-25 14:17:34.328 1605 2091 W BaseMiuiPhoneWindowManager: keyCode:26 down:true eventTime:12643277 downTime:12643277 policyFlags:22000000 flags:8 deviceId:5 isScreenOn:true keyguardActive:false repeatCount:0

10-25 14:17:34.434 1605 2091 W BaseMiuiPhoneWindowManager: keyCode:26 down:false eventTime:12643384 downTime:12643277 policyFlags:22000000 flags:8 deviceId:5 isScreenOn:true keyguardActive:false repeatCount:0

10-25 14:17:34.435 1605 1605 I WindowManager: Started going to sleep... (why=2)
10-25 14:17:34.762 1605 1709 I DisplayPowerController: Blocking screen off
10-25 14:17:34.776 1605 1709 I DisplayPowerController: Unblocked screen off after 14 ms
10-25 14:17:34.777 1605 1709 I WindowManager: Screen turned off...

10-25 14:17:35.319 1605 2453 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.miui.home/.launcher.Launcher} from uid 1000
10-25 14:17:35.324 1605 2453 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{da4a56d com.miui.home} is now in focus and seems to be in full-screen mode
10-25 14:17:35.324 1605 2453 E ActivityTrigger: activityResumeTrigger: not whiteListedcom.miui.home/com.miui.home.launcher.Launcher/4063011
10-25 14:17:35.326 1605 2453 W System.err: java.lang.RuntimeException
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.DockedStackDividerController.notifyDockedStackMinimizedChanged(DockedStackDividerController.java:481)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.DockedStackDividerController.setMinimizedDockedStack(DockedStackDividerController.java:808)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.DockedStackDividerController.setMinimizedDockedStack(DockedStackDividerController.java:700)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.DockedStackDividerController.checkMinimizeChanged(DockedStackDividerController.java:665)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.DockedStackDividerController.notifyAppVisibilityChanged(DockedStackDividerController.java:580)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.AppWindowToken.setVisibility(AppWindowToken.java:457)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.wm.AppWindowContainerController.setVisibility(AppWindowContainerController.java:461)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityRecord.setVisibility(ActivityRecord.java:1780)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStack.resumeTopActivityInnerLocked(ActivityStack.java:2756)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStack.resumeTopActivityUncheckedLocked(ActivityStack.java:2350)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStackSupervisor.resumeFocusedStackTopActivityLocked(ActivityStackSupervisor.java:2190)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStackSupervisor.resumeFocusedStackTopActivityLocked(ActivityStackSupervisor.java:2151)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStack.moveTaskToFrontLocked(ActivityStack.java:4872)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStarter.setTargetStackAndMoveToFrontIfNeeded(ActivityStarter.java:1785)
10-25 14:17:35.326 1605 2453 W System.err: at com.android.server.am.ActivityStarter.startActivityUnchecked(ActivityStarter.java:1246)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityStarter.startActivity(ActivityStarter.java:1121)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityStarter.startActivity(ActivityStarter.java:630)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityStarter.startActivityLocked(ActivityStarter.java:278)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityStarter.startActivityMayWait(ActivityStarter.java:936)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityManagerService.startActivityAsUser(ActivityManagerService.java:4722)
10-25 14:17:35.327 1605 2453 W System.err: at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:2314)
10-25 14:17:35.327 1605 2453 W System.err: at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:3049)
10-25 14:17:35.327 1605 2453 W System.err: at android.os.Binder.execTransact(Binder.java:681)
10-25 14:17:35.327 2461 3254 D Divider : onDockedStackMinimizedChanged minimized=true animDuration=0

可以看到，這里會進(jìn)行最小化的操作，也就是說到滅屏前是完全沒問題的，那么我們將重點(diǎn)放在滅屏后

然后對比正常日志，

10-25 16:28:33.764  1605  2493 W ActivityManager: Force removing ActivityRecord{d37a66f u0 android.server.cts/.TestActivity t59}: app died, no saved state

10-25 16:28:33.788 2461 3254 D Divider : onDockedStackMinimizedChanged minimized=false animDuration=0
10-25 16:28:33.802 2461 3254 D Divider : onDividerVisibilityChanged visible=false
10-25 16:28:33.836 2461 2461 D EventBus: [2461, u0] -> DividerView [0x284c897, P1] onBusEvent(MultiWindowStateChangedEvent)

異常日志：

10-25 09:46:49.264  2461  4530 D Divider : onDockedStackMinimizedChanged minimized=false animDuration=250

10-25 09:46:49.934  1605  3297 W ActivityManager: Force removing ActivityRecord{c57c476 u0 android.server.cts/.TestActivity t17}: app died, no saved state

10-25 09:46:49.947 2461 2480 D Divider : onDockedStackExistsChanged exists=false
10-25 09:46:49.964 2461 2480 D Divider : onDividerVisibilityChanged visible=false

10-25 09:46:49.977  2461  2461 D EventBus: [2461, u0]  -> DividerView [0x284c897, P1] onBusEvent(MultiWindowStateChangedEvent)

正常日志是將測試進(jìn)程force-stop后再進(jìn)行銷毀工作，DividerView最小化，然后銷毀；異常日志是DividerView最小化在前面執(zhí)行，導(dǎo)致case fail；

然后我們仔細(xì)觀察異常log，就可以看出原因：

首先，亮屏后(執(zhí)行菜單鍵)，可以看到提前最小化的棧在

10-25 09:46:49.160 1605 5703 W BaseMiuiPhoneWindowManager: keyCode:82 down:true eventTime:846050 downTime:846050 policyFlags:2b000000 flags:0 deviceId:-1 isScreenOn:true keyguardActive:false repeatCount:0
10-25 09:46:49.162 14122 14122 I Input : injectKeyEvent: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MENU, scanCode=0, metaState=0, flags=0x0, repeatCount=0, eventTime=846050, downTime=846050, deviceId=-1, source=0x101 }
10-25 09:46:49.162 1605 5703 W BaseMiuiPhoneWindowManager: keyCode:82 down:false eventTime:846050 downTime:846050 policyFlags:2b000000 flags:0 deviceId:-1 isScreenOn:true keyguardActive:false repeatCount:0
10-25 09:46:49.182 2461 2461 D RecentsImpl: startRecentsActivity runningTask: ComponentInfo{com.miui.home/com.miui.home.launcher.Launcher}

10-25 09:46:49.262 1605 2074 W System.err: java.lang.RuntimeException

10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.DockedStackDividerController.notifyDockedStackMinimizedChanged(DockedStackDividerController.java:481)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.DockedStackDividerController.animateForMinimizedDockedStack(DockedStackDividerController.java:862)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.DockedStackDividerController.animate(DockedStackDividerController.java:821)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.WindowAnimator.animate(WindowAnimator.java:250)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.WindowAnimator.lambda$-com_android_server_wm_WindowAnimator_4083(WindowAnimator.java:109)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.-$Lambda$OQfQhd_xsxt9hoLAjIbVfOwa-jY.$m$0(Unknown Source:4)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.wm.-$Lambda$OQfQhd_xsxt9hoLAjIbVfOwa-jY.doFrame(Unknown Source:0)
10-25 09:46:49.262 1605 2074 W System.err: at android.view.Choreographer$CallbackRecord.run(Choreographer.java:1024)
10-25 09:46:49.262 1605 2074 W System.err: at android.view.Choreographer.doCallbacks(Choreographer.java:838)
10-25 09:46:49.262 1605 2074 W System.err: at android.view.Choreographer.doFrame(Choreographer.java:766)
10-25 09:46:49.262 1605 2074 W System.err: at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:1012)
10-25 09:46:49.262 1605 2074 W System.err: at android.os.Handler.handleCallback(Handler.java:792)
10-25 09:46:49.262 1605 2074 W System.err: at android.os.Handler.dispatchMessage(Handler.java:98)
10-25 09:46:49.262 1605 2074 W System.err: at android.os.Looper.loop(Looper.java:176)
10-25 09:46:49.262 1605 2074 W System.err: at android.os.HandlerThread.run(HandlerThread.java:65)
10-25 09:46:49.262 1605 2074 W System.err: at com.android.server.ServiceThread.run(ServiceThread.java:46)
10-25 09:46:49.262 4260 4532 D PowerKeeper: PowerStateMachine:onDockedStackMinimizedChanged minimized=false
10-25 09:46:49.262 4260 4356 D PowerKeeper: PowerStateMachine:EVENT_ID_MULTI_SCREEN_MINIMIZED mIsMultiScreenMinimized=false
10-25 09:46:49.264 2461 4530 D Divider : onDockedStackMinimizedChanged minimized=false animDuration=250

是執(zhí)行DockedStackDividerController.animate操作導(dǎo)致的最小化，在往前看看，找到原因了

10-25 09:46:49.215 2461 2461 D EventBus: [2461, u0] -> DividerView [0x284c897, P1] onBusEvent(RecentsActivityStartingEvent)
10-25 09:46:49.215 2461 2461 D EventBus: [2461, u0] onBusEvent(RecentsActivityStartingEvent) duration: 131 microseconds, avg: 71
10-25 09:46:49.215 1605 2091 I InputReader: Reconfiguring input devices. changes=0x00000004

1144    public final void onBusEvent(RecentsDrawnEvent drawnEvent) {
1145        if (mState.animateAfterRecentsDrawn) {
1146            mState.animateAfterRecentsDrawn = false;
1147            updateDockSide();
1148
1149            mHandler.post(() -> {
1150                // Delay switching resizing mode because this might cause jank in recents animation
1151                // that's longer than this animation.
1152                stopDragging(getCurrentPosition(), mSnapAlgorithm.getMiddleTarget(),
1153                        mLongPressEntraceAnimDuration, Interpolators.FAST_OUT_SLOW_IN,
1154                        200 /* endDelay */);
1155            });
1156        }
1157        if (mState.growAfterRecentsDrawn) {
1158            mState.growAfterRecentsDrawn = false;
1159            updateDockSide();
1160            EventBus.getDefault().send(new RecentsGrowingEvent());
1161            stopDragging(getCurrentPosition(), mSnapAlgorithm.getMiddleTarget(), 336,
1162                    Interpolators.FAST_OUT_SLOW_IN);
1163        }
1164    }

10-25 09:46:49.258 2461 2461 D EventBus: [2461, u0] -> DividerView [0x284c897, P1] onBusEvent(RecentsDrawnEvent)
10-25 09:46:49.259 2461 2461 D EventBus: [2461, u0] onBusEvent(RecentsDrawnEvent) duration: 8 microseconds, avg: 68

407    public void stopDragging(int position, float velocity, boolean avoidDismissStart,
408            boolean logMetrics) {
409        mHandle.setTouching(false, true /* animate */);
410        fling(position, velocity, avoidDismissStart, logMetrics);
411        mWindowManager.setSlippery(true);
412        releaseBackground();
413    }

可以很明顯的看到，DividerView會執(zhí)行一個滑動操作，那么應(yīng)該會執(zhí)行到animate，將狀態(tài)從最小化狀態(tài)還原。而我們MIUI默認(rèn)將menu菜單鍵的功能設(shè)置為最近任務(wù)功能，懷疑是沒有設(shè)置正確導(dǎo)致的問題

那么我們可以將Skip Screen lock開關(guān)打開來測試了，將菜單鍵置為本來功能，發(fā)現(xiàn)case果然pass；這里我們也可以看到為什么Skip Screen lock開關(guān)關(guān)閉也能過了，因?yàn)橐恢睕]有解鎖，導(dǎo)致DividerView沒有走后面的還原過程，雖然case也是pass的，但是這其實(shí)不符合case本身的用意

問題總結(jié)

問題本身不難，但是這樣無用的分析是浪費(fèi)資源的

1.再次強(qiáng)調(diào)，讓所有測試都明確測試配置
2.建議維護(hù)一個wiki，維護(hù)沒有正確設(shè)置可能造成的問題，防止這種情況再次發(fā)生，做無用的分析

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成，瀏覽時(shí)請結(jié)合常識與多方信息審慎甄別。
平臺聲明：文章內(nèi)容（如有圖片或視頻亦包括在內(nèi)）由作者上傳并發(fā)布，文章內(nèi)容僅代表作者本人觀點(diǎn)，簡書系信息發(fā)布平臺，僅提供信息存儲服務(wù)。

相關(guān)閱讀更多精彩內(nèi)容

友情鏈接更多精彩內(nèi)容