SystemUI子进程处理截屏手势弹窗出现ANR
现象：从下拉中点击截屏，弹出学习截屏的弹窗后，点击界面无效区域，过一会就发生ANR
分析：
-
Perfetto
从trace中看到两次点击事件，第一次DOWN和UP分发正常，第二次DOWN和UP分发不正常。第二次iq和oq都正常下降到0，但是wq一直在累积，并且客户端的aq也没有收到输入事件
-
log
正常log流程
一次motion事件分发
09-20 11:23:14.208 8019 8134 D InputDispatcher: dispatchEventToCurrentInputTargets
准备分发
09-20 11:23:14.208 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ prepareDispatchCycle - flags=FOREGROUND | SPLIT | DISPATCH\_AS\_IS, globalScaleFactor=1.000000, pointerIds=00000000000000000000000000000001
通过socket发送给客户端的窗口ScreenShotLearningDialog，此时oq会减1，wq会加1，mAnrTracker记录当前事件
09-20 11:23:14.208 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ startDispatchCycle
客户端接收输入事件的Looper唤醒消费输入事件
09-20 11:23:14.209 5452 5452 D InputEventReceiver: channel 'c8b6716 ScreenShotLearningDialog (client)' \~ Consuming input events, consumeBatches=false, frameTime=-1
从socket读取到事件
09-20 11:23:14.210 5452 5452 D InputEventReceiver: channel 'c8b6716 ScreenShotLearningDialog (client)' \~ Received motion event.
转换成MotionEvent，分发给java端的InputEventReceiver.dispatchInputEvent
09-20 11:23:14.210 5452 5452 D InputEventReceiver: channel 'c8b6716 ScreenShotLearningDialog (client)' \~ Dispatching input event.
事件处理完成后，java端InputEventReceiver调用finishInputEvent，并通过socket告知InputDispatcher
09-20 11:23:14.227 5452 5452 D InputEventReceiver: channel 'c8b6716 ScreenShotLearningDialog (client)' \~ Finished input event.
InputDispatcher回调handleReceiveCallback，并调用finishDispatchCycleLocked->doDispatchCycleFinishedCommand，wq减1，并且从mAnrTracker中移除
09-20 11:23:14.227 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ finishDispatchCycle - seq=387, handled=true
尝试继续从oq中获取事件继续分发
09-20 11:23:14.227 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ startDispatchCycle
出问题的log
只有system\_server端的log，没有客户端的log，即客户端没有接收到事件
09-20 11:23:28.013 8019 8134 D InputDispatcher: dispatchEventToCurrentInputTargets
09-20 11:23:28.013 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ prepareDispatchCycle - flags=FOREGROUND | SPLIT | DISPATCH\_AS\_IS, globalScaleFactor=1.000000, pointerIds=00000000000000000000000000000001
09-20 11:23:28.013 8019 8134 D InputDispatcher: channel 'c8b6716 ScreenShotLearningDialog (server)' \~ startDispatchCycle
09-20 11:23:32.886 8019 8134 W InputDispatcher: Window c8b6716 ScreenShotLearningDialog (server) is unresponsive: c8b6716 ScreenShotLearningDialog (server) is not responding. Waited 5005ms for MotionEvent(deviceId=5, eventTime=1851103240000, source=TOUCHSCREEN, displayId=0, action=DOWN, actionButton=0x00000000, flags=0x00000000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=\[0: (147.8, 1040.4)]), policyFlags=0x62000000
09-20 11:23:32.886 8019 8134 W InputDispatcher: Canceling events for c8b6716 ScreenShotLearningDialog (server) because it is unresponsive
-
anr trace文件
没有看到堆栈信息，进程中对应的线程状态
Subject: Input dispatching timed out (c8b6716 ScreenShotLearningDialog (server) is not responding. Waited 5005ms for MotionEvent(deviceId=5, eventTime=1851103240000, source=TOUCHSCREEN, displayId=0, action=DOWN, actionButton=0x00000000, flags=0x00000000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=[0: (147.8, 1040.4)]), policyFlags=0x62000000)
RssHwmKb: 195628
RssKb: 172808
RssAnonKb: 48156
RssShmemKb: 1696
VmSwapKb: 19152
--- CriticalEventLog ---
capacity: 20
timestamp_ms: 1726827812924
window_ms: 300000
----- dumping pid: 5452 at 1856113
libdebuggerd_client: failed to read status response from tombstoned: timeout reached?
----- Waiting Channels: pid 5452 at 2024-09-20 11:23:32.892483187+0100 -----
Cmd line: com.android.systemui:screenshot
sysTid=5452 do_freezer_trap
sysTid=5457 do_freezer_trap
sysTid=5458 do_freezer_trap
sysTid=5459 do_freezer_trap
sysTid=5460 do_freezer_trap
sysTid=5461 do_freezer_trap
sysTid=5462 do_freezer_trap
sysTid=5463 do_freezer_trap
sysTid=5464 do_freezer_trap
sysTid=5465 do_freezer_trap
sysTid=5466 do_freezer_trap
sysTid=5467 do_freezer_trap
sysTid=5471 do_freezer_trap
sysTid=5472 do_freezer_trap
sysTid=5473 do_freezer_trap
sysTid=5474 do_freezer_trap
sysTid=5475 do_freezer_trap
sysTid=5477 do_freezer_trap
sysTid=5481 do_freezer_trap
sysTid=5483 do_freezer_trap
sysTid=5484 do_freezer_trap
sysTid=5485 do_freezer_trap
sysTid=5486 do_freezer_trap
sysTid=5487 do_freezer_trap
sysTid=5488 do_freezer_trap
sysTid=5491 do_freezer_trap
sysTid=5492 do_freezer_trap
sysTid=5493 do_freezer_trap
sysTid=5494 do_freezer_trap
sysTid=5495 do_freezer_trap
sysTid=5496 do_freezer_trap
sysTid=5497 do_freezer_trap
sysTid=5498 do_freezer_trap
sysTid=5500 do_freezer_trap
sysTid=5501 do_freezer_trap
sysTid=5502 do_freezer_trap
sysTid=5503 do_freezer_trap
sysTid=5504 do_freezer_trap
sysTid=5505 do_freezer_trap
sysTid=5507 do_freezer_trap
sysTid=5508 do_freezer_trap
sysTid=5509 do_freezer_trap
sysTid=5510 do_freezer_trap
sysTid=5511 do_freezer_trap
sysTid=5512 do_freezer_trap
sysTid=5513 do_freezer_trap
sysTid=5514 do_freezer_trap
sysTid=5515 do_freezer_trap
sysTid=5516 do_freezer_trap
sysTid=5519 do_freezer_trap
sysTid=5520 do_freezer_trap
sysTid=5521 do_freezer_trap
sysTid=5523 do_freezer_trap
sysTid=5525 do_freezer_trap
----- end 5452 -----
libdebuggerd_client: failed to read status response from tombstoned: Try again
----- Waiting Channels: pid 5452 at 2024-09-20 11:23:42.912211187+0100 -----
Cmd line: com.android.systemui:screenshot
sysTid=5452 do_freezer_trap
sysTid=5457 do_freezer_trap
sysTid=5458 do_freezer_trap
sysTid=5459 do_freezer_trap
sysTid=5460 do_freezer_trap
sysTid=5461 do_freezer_trap
sysTid=5462 do_freezer_trap
sysTid=5463 do_freezer_trap
sysTid=5464 do_freezer_trap
sysTid=5465 do_freezer_trap
sysTid=5466 do_freezer_trap
sysTid=5467 do_freezer_trap
sysTid=5471 do_freezer_trap
sysTid=5472 do_freezer_trap
sysTid=5473 do_freezer_trap
sysTid=5474 do_freezer_trap
sysTid=5475 do_freezer_trap
sysTid=5477 do_freezer_trap
sysTid=5481 do_freezer_trap
sysTid=5483 do_freezer_trap
sysTid=5484 do_freezer_trap
sysTid=5485 do_freezer_trap
sysTid=5486 do_freezer_trap
sysTid=5487 do_freezer_trap
sysTid=5488 do_freezer_trap
sysTid=5491 do_freezer_trap
sysTid=5492 do_freezer_trap
sysTid=5493 do_freezer_trap
sysTid=5494 do_freezer_trap
sysTid=5495 do_freezer_trap
sysTid=5496 do_freezer_trap
sysTid=5497 do_freezer_trap
sysTid=5498 do_freezer_trap
sysTid=5500 do_freezer_trap
sysTid=5501 do_freezer_trap
sysTid=5502 do_freezer_trap
sysTid=5503 do_freezer_trap
sysTid=5504 do_freezer_trap
sysTid=5505 do_freezer_trap
sysTid=5507 do_freezer_trap
sysTid=5508 do_freezer_trap
sysTid=5509 do_freezer_trap
sysTid=5510 do_freezer_trap
sysTid=5511 do_freezer_trap
sysTid=5512 do_freezer_trap
sysTid=5513 do_freezer_trap
sysTid=5514 do_freezer_trap
sysTid=5515 do_freezer_trap
sysTid=5516 do_freezer_trap
sysTid=5519 do_freezer_trap
sysTid=5520 do_freezer_trap
sysTid=5521 do_freezer_trap
sysTid=5523 do_freezer_trap
sysTid=5525 do_freezer_trap
----- end 5452 -----
参考文章www.jianshu.com/p/e62892149…
在log中也看到
09-20 11:23:15.406 8019 8121 I am_freeze: [5452,com.android.systemui:screenshot]
通过adb shell cmd activity watch-uids --oom [uid]观察oomadj的变化
# Start proc 475:com.android.systemui:screenshot/u0a180 for service {com.android.systemui/com.android.systemui.screenshot.TakeScreenshotService}
# Making exec-service: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}
# Raise to service: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}, due to ProcessRecord{ade678e 8019:system/1000} adj=0 procState=BFGS
# Set 475 com.android.systemui:screenshot adj 0: service
# Proc state change of com.android.systemui:screenshot to BFGS (5): service
# Making empty: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}
# Raise to service: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}, due to ProcessRecord{ade678e 8019:system/1000} adj=100 procState=BFGS
# Set 475 com.android.systemui:screenshot adj 100: service
# Making exec-service: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}
# Set 475 com.android.systemui:screenshot adj 0: exec-service
# Setting sched group of com.android.systemui:screenshot to 0: exec-service
# Proc state change of com.android.systemui:screenshot to SVC (10): exec-service
# Making empty: ProcessRecord{34d1f6d 475:com.android.systemui:screenshot/u0a180}
# Set 475 com.android.systemui:screenshot adj 1001: cch-empty
# Proc state change of com.android.systemui:screenshot to CEM (19): cch-empty
# Set 475 com.android.systemui:screenshot adj 905: cch-empty
可以看到弹窗出现的时候adj是905，进程的状态是CACHED_EMPTY
命令行获取冻结相关的变量信息
$ adb shell dumpsys activity settings
use_freezer=true //是否支持冻结
freeze_statsd_sample_rate=0.1
freeze_debounce_timeout=10000 // adj已经是CACHED_EMPTY后，延时10s就会开始冻结
freeze_exempt_inst_pkg=false
freeze_binder_enabled=true
freeze_binder_threshold=1000
freeze_binder_divisor=4
freeze_binder_offset=500
freeze_binder_callback_enabled=true
freeze_binder_callback_throttle=10000
freeze_binder_async_threshold=1024
Apps frozen: 17 //冻结app的列表，代码一共有17个app进程被冻结
26599270: 6324 com.google.android.apps.wellbeing
26603762: 6391 com.google.android.googlequicksearchbox:googleapp
26384926: 6592 com.google.android.webview:webview_service
26610841: 6676 com.google.android.apps.photos
....
-
再看Perfetto
1 第一次触摸down，up事件处理及时
2 第二次触摸后wq一直在累加，且没有减少
3 com.android.systemui:screenshot进程被冻结，所以2的触摸事件无法被处理
从3中查看主线程com.android.systemui:screenshot的runnable片段，可以知道是被SystemService的CachedAppOptimi线程唤醒
从下图可以看出SystemService的CachedAppOptimi线程正在进行冻结com.android.systemui:screenshot的操作
