anr问题
最近新开发的功能引起第三方app频繁anr,解决问题过程中发现本次anr与mFocusedWindow有十分密切关系,记录如下:
问题:anr,用户在加减音量的时候会引起anr,如果是touch事件则不会anr。
日志:
12-01 16:01:10.669 1256 2171 I am_anr : [0,30522,com.ggp.ggpdemo,552124230,Input dispatching timed out (Application does not have a focused window)]
"main" prio=5 tid=1 Native
| group="main" sCount=1 ucsCount=0 flags=1 obj=0x71b8f6e8 self=0xb400007c2bee2c00
| sysTid=30522 nice=-10 cgrp=top-app sched=0/0 handle=0x7c2d5444f8
| state=S schedstat=( 211713206 24400522 338 ) utm=18 stm=2 core=1 HZ=100
| stack=0x7fe65a4000-0x7fe65a6000 stackSize=8188KB
| held mutexes=
native: #00 pc 00000000000e8f0c /apex/com.android.runtime/lib64/bionic/libc.so (__epoll_pwait+12)
native: #01 pc 0000000000017ea8 /system/lib64/libutils.so (android::Looper::pollInner(int)+184)
native: #02 pc 0000000000017d84 /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+116)
native: #03 pc 00000000001562b4 /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+48)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:335)
at android.os.Looper.loopOnce(Looper.java:173)
at android.os.Looper.loop(Looper.java:379)
at android.app.ActivityThread.main(ActivityThread.java:9052)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:567)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1018)
看当前的dump信息发现有两个mFocusedWindow
λ adb shell dumpsys window |grep mFocus
mFocusedApp=ActivityRecord{8fe14de u0 com.ggp.ggpdemo/.MainActivity t47}
mFocusedWindow=Window{ace421d u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity}
mFocusedApp=ActivityRecord{21ff021 u0 com.ggp.ggpdemo/.MainActivity t50}
mFocusedWindow=Window{64a4587 u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity}
很明显当前的mFocusedWindow出现问题,从dump信息然后结合代码就可以看到mFocusedWindow更新流程异常。由于公司代码就不上传具体调用过程。
查到focused异常这个bug就很好调查和解决了
不过这个bug很明显的一个的问题是我们将key事件传递给了一个NOT_FOCUSABLE NOT_TOUCHABLE的window。那么猜测即使focused错误了,如果这个window接受key事件,那么也应该不会anr,于是我们写了一个demo,将activity设置为not_focusable.然后加减音量也复现了相同的anr问题。
setContentView(R.layout.activity_main);
//getWindow().setFlags(WindowManager.LayoutParams.FLAG_NOT_FOCUSABLE, WindowManager.LayoutParams.FLAG_NOT_FOCUSABLE);
//getWindow().setFlags(WindowManager.LayoutParams.FLAG_NOT_TOUCHABLE, WindowManager.LayoutParams.FLAG_NOT_TOUCHABLE);
继续调查一下keyEvent的下发异常导致anr流程,在发生anr的时候有两行很明显的日志
12-01 18:23:57.858 1263 2416 W InputDispatcher: Waiting because no window has focus but ActivityRecord{dca0e8f u0 com.ggp.ggpdemo/.MainActivity t77} may eventually add a window when it finishes starting up. Will wait for 5000ms
12-01 18:24:02.861 1263 2416 E InputDispatcher: Dropping KEY event because there is no focused window
12-01 18:24:02.949 1263 2416 W InputDispatcher: Waiting because no window has focus but ActivityRecord{dca0e8f u0 com.ggp.ggpdemo/.MainActivity t77} may eventually add a window when it finishes starting up. Will wait for 5000ms
找到InputDispatch.cpp,查看一keyEvent下发流程,找到关键日志打印,这里我们还可以打印一下
inputDispatcher->dispatchOnceInnerLocked() -> dispatchKeyLocked() -> findFocusedWindowIargetsLocked()
InputEventInjectionResult InputDispatcher::findFocusedWindowTargetsLocked(
nsecs_t currentTime, const EventEntry& entry, std::vector<InputTarget>& inputTargets,
nsecs_t* nextWakeupTime) {
std::string reason;
sp<InputWindowHandle> focusedWindowHandle = getFocusedWindowHandleLocked(displayId);
std::shared_ptr<InputApplicationHandle> focusedApplicationHandle =
getValueByKey(mFocusedApplicationHandlesByDisplay, displayId);
//日志注释很明确,no focused window ANR
// Compatibility behavior: raise ANR if there is a focused application, but no focused window.
// Only start counting when we have a focused event to dispatch. The ANR is canceled if we
// start interacting with another application via touch (app switch). This code can be removed
// if the "no focused window ANR" is moved to the policy. Input doesn't know whether
// an app is expected to have a focused window.
if (focusedWindowHandle == nullptr && focusedApplicationHandle != nullptr) {
if (!mNoFocusedWindowTimeoutTime.has_value()) {
// We just discovered that there's no focused window. Start the ANR timer
std::chrono::nanoseconds timeout = focusedApplicationHandle->getDispatchingTimeout(
DEFAULT_INPUT_DISPATCHING_TIMEOUT);
mNoFocusedWindowTimeoutTime = currentTime + timeout.count();
mAwaitedFocusedApplication = focusedApplicationHandle;
mAwaitedApplicationDisplayId = displayId;
ALOGW("Waiting because no window has focus but %s may eventually add a "
"window when it finishes starting up. Will wait for %" PRId64 "ms",
mAwaitedFocusedApplication->getName().c_str(), millis(timeout));
*nextWakeupTime = *mNoFocusedWindowTimeoutTime;
return InputEventInjectionResult::PENDING;
} else if (currentTime > *mNoFocusedWindowTimeoutTime) {
// Already raised ANR. Drop the event
ALOGE("Dropping %s event because there is no focused window",
NamedEnum::string(entry.type).c_str());
return InputEventInjectionResult::FAILED;
} else {
// Still waiting for the focused window
return InputEventInjectionResult::PENDING;
}
}
return InputEventInjectionResult::SUCCEEDED;
}
focusedwindowHandle获取
没调查,不知道,不晓得,有兴趣的可以自己看一下。。。
focusedwindowHandle与mFocusedWindow必然是有一定的关系的,否则即使mFocusedWindow更新出错,也不会出现anr的。不过具体关系我没有调查,还需要一点时间来理一理。
mFocusedWindow更新流程
据此我们继续调查了mFocusedWindow的调用流程,代码不做输入,堆栈记录如下:
情景一
当前touch事件落在focusedWindow之外会引起一次mFocusedWindow更新,一般来说都是多窗口操作会引起这一步切换,比如pip,分屏,freeform
2021-12-01 12:23:08.986 1256-2126/system_process D/ggpff: focusChangedLw lastFocus = Window{6252892 u0 com.ss.android.ugc.aweme/com.ss.android.ugc.aweme.splash.SplashActivity} newFocus = Window{d3750ff u0 cn.nubia.mms/cn.nubia.mms.tab.MmsMainActivity}java.lang.Throwable
at com.android.server.wm.DisplayPolicy.focusChangedLw(DisplayPolicy.java:2656)
at com.android.server.wm.DisplayContent.updateFocusedWindowLocked(DisplayContent.java:3649)
at com.android.server.wm.RootWindowContainer.updateFocusedWindowLocked(RootWindowContainer.java:493)
at com.android.server.wm.WindowManagerService.updateFocusedWindowLocked(WindowManagerService.java:6307)
at com.android.server.wm.ActivityTaskManagerService.setResumedActivityUncheckLocked(ActivityTaskManagerService.java:4936)
at com.android.server.wm.TaskDisplayArea.positionChildTaskAt(TaskDisplayArea.java:483)
at com.android.server.wm.TaskDisplayArea.positionChildAt(TaskDisplayArea.java:423)
at com.android.server.wm.Task.moveToFront(Task.java:5731)
at com.android.server.wm.ActivityRecord.moveFocusableActivityToTop(ActivityRecord.java:2945)
at com.android.server.wm.ActivityTaskManagerService.setFocusedTask(ActivityTaskManagerService.java:2209)
at com.android.server.wm.WindowManagerService.handleTaskFocusChange(WindowManagerService.java:9071)
at com.android.server.wm.WindowManagerService.onPointerDownOutsideFocusLocked(WindowManagerService.java:9035)
at com.android.server.wm.WindowManagerService.access$1600(WindowManagerService.java:345)
at com.android.server.wm.WindowManagerService$H.handleMessage(WindowManagerService.java:5742)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loopOnce(Looper.java:238)
at android.os.Looper.loop(Looper.java:379)
at android.os.HandlerThread.run(HandlerThread.java:67)
at com.android.server.ServiceThread.run(ServiceThread.java:44)
情景二
startActivity必然会引起mFocusedWindow切换,这个切换过程有两步,第一步是切换为null,第二步切换为新window(切换为null必然是有原因的,为什么没有直接切换到新window,具体什么原因我没有调查)
第一步,切换为null
2021-12-01 15:35:32.395 1256-3319/system_process D/ggpff: focusChangedLw lastFocus = Window{db4af75 u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity} newFocus = nulljava.lang.Throwable
at com.android.server.wm.DisplayPolicy.focusChangedLw(DisplayPolicy.java:2656)
at com.android.server.wm.DisplayContent.updateFocusedWindowLocked(DisplayContent.java:3649)
at com.android.server.wm.RootWindowContainer.updateFocusedWindowLocked(RootWindowContainer.java:493)
at com.android.server.wm.WindowManagerService.updateFocusedWindowLocked(WindowManagerService.java:6307)
at com.android.server.wm.ActivityTaskManagerService.setResumedActivityUncheckLocked(ActivityTaskManagerService.java:4936)
at com.android.server.wm.Task.onActivityStateChanged(Task.java:2297)
at com.android.server.wm.ActivityRecord.setState(ActivityRecord.java:5050)
at com.android.server.wm.Task.minimalResumeActivityLocked(Task.java:5795)
at com.android.server.wm.ActivityTaskSupervisor.realStartActivityLocked(ActivityTaskSupervisor.java:1044)
at com.android.server.wm.ActivityTaskSupervisor.startSpecificActivity(ActivityTaskSupervisor.java:1115)
at com.android.server.wm.Task.resumeTopActivityInnerLocked(Task.java:6910)
at com.android.server.wm.Task.resumeTopActivityUncheckedLocked(Task.java:6353)
at com.android.server.wm.RootWindowContainer.resumeFocusedTasksTopActivities(RootWindowContainer.java:2659)
at com.android.server.wm.RootWindowContainer.resumeFocusedTasksTopActivities(RootWindowContainer.java:2645)
at com.android.server.wm.Task.completePauseLocked(Task.java:6139)
at com.android.server.wm.ActivityRecord.activityPaused(ActivityRecord.java:5731)
at com.android.server.wm.ActivityClientController.activityPaused(ActivityClientController.java:173)
at android.app.IActivityClientController$Stub.onTransact(IActivityClientController.java:549)
at com.android.server.wm.ActivityClientController.onTransact(ActivityClientController.java:119)
at android.os.Binder.execTransactInternal(Binder.java:1198)
第二步,切换为新window
2021-12-01 15:35:32.459 1256-2003/system_process D/ggpff: focusChangedLw lastFocus = null newFocus = Window{5f5716a u0 com.ggp.ggpdemo/com.ggp.ggpdemo.SecondActivity}java.lang.Throwable
at com.android.server.wm.DisplayPolicy.focusChangedLw(DisplayPolicy.java:2656)
at com.android.server.wm.DisplayContent.updateFocusedWindowLocked(DisplayContent.java:3649)
at com.android.server.wm.RootWindowContainer.updateFocusedWindowLocked(RootWindowContainer.java:493)
at com.android.server.wm.WindowManagerService.updateFocusedWindowLocked(WindowManagerService.java:6307)
at com.android.server.wm.WindowManagerService.relayoutWindow(WindowManagerService.java:2619)
at com.android.server.wm.Session.relayout(Session.java:235)
at android.view.IWindowSession$Stub.onTransact(IWindowSession.java:735)
at com.android.server.wm.Session.onTransact(Session.java:169)
at android.os.Binder.execTransactInternal(Binder.java:1198)
at android.os.Binder.execTransact(Binder.java:1157)
2021-12-01 15:47:27.557 1256-9937/system_process D/ggpff: focusChangedLw lastFocus = Window{43cbe9e u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity} newFocus = Window{aa6ebef u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity}java.lang.Throwable
at com.android.server.wm.DisplayPolicy.focusChangedLw(DisplayPolicy.java:2656)
at com.android.server.wm.DisplayContent.updateFocusedWindowLocked(DisplayContent.java:3649)
at com.android.server.wm.RootWindowContainer.updateFocusedWindowLocked(RootWindowContainer.java:493)
at com.android.server.wm.WindowManagerService.updateFocusedWindowLocked(WindowManagerService.java:6307)
at com.android.server.wm.WindowManagerService.addWindow(WindowManagerService.java:1929)
at com.android.server.wm.Session.addToDisplayAsUser(Session.java:204)
at android.view.IWindowSession$Stub.onTransact(IWindowSession.java:636)
at com.android.server.wm.Session.onTransact(Session.java:169)
at android.os.Binder.execTransactInternal(Binder.java:1198)
at android.os.Binder.execTransact(Binder.java:1157)
情景三
add或者remove window也必然会引起mFocusedWindow切换
2021-12-01 15:47:39.353 1256-9937/system_process D/ggpff: focusChangedLw lastFocus = Window{aa6ebef u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity EXITING} newFocus = Window{43cbe9e u0 com.ggp.ggpdemo/com.ggp.ggpdemo.MainActivity}java.lang.Throwable
at com.android.server.wm.DisplayPolicy.focusChangedLw(DisplayPolicy.java:2656)
at com.android.server.wm.DisplayContent.updateFocusedWindowLocked(DisplayContent.java:3649)
at com.android.server.wm.RootWindowContainer.updateFocusedWindowLocked(RootWindowContainer.java:493)
at com.android.server.wm.WindowManagerService.updateFocusedWindowLocked(WindowManagerService.java:6307)
at com.android.server.wm.WindowState.setupWindowForRemoveOnExit(WindowState.java:2698)
at com.android.server.wm.WindowState.removeIfPossible(WindowState.java:2666)
at com.android.server.wm.WindowState.removeIfPossible(WindowState.java:2544)
at com.android.server.wm.WindowManagerService.removeWindow(WindowManagerService.java:2126)
at com.android.server.wm.Session.remove(Session.java:218)
at android.view.IWindowSession$Stub.onTransact(IWindowSession.java:691)
at com.android.server.wm.Session.onTransact(Session.java:169)
at android.os.Binder.execTransactInternal(Binder.java:1198)
at android.os.Binder.execTransact(Binder.java:1157)