原创内容,转载请注明出处,多谢配合。
经过前面八篇文章的铺垫,应该对Input系统有了全方面的了解了,最后一篇打算简单整理下Input相关问题分析。
Input相关问题主要包括这么几类:
一、 tp报点问题
这是偏底层的问题,主要是InputReader读取event及其之间的阶段。
1)查看支持的设备节点
/dev/input $ ls
event0 event1 event2 event3 event4 event5 event6
这里常见的event节点对应的设备: 比如event0对应key、event3对应motion
2)查看报点情况:
- adb命令来看
adb shell getevent -ltr
打印的信息:
[ 83.879437] /dev/input/event3: EV_ABS ABS_MT_POSITION_X 00000100
[ 83.879437] /dev/input/event3: EV_ABS ABS_MT_POSITION_Y 0000065b
[ 83.879437] /dev/input/event3: EV_ABS ABS_MT_TOUCH_MAJOR 00000046
[ 83.879437] /dev/input/event3: EV_SYN SYN_REPORT 00000000 rate 114
[ 83.887649] /dev/input/event3: EV_ABS ABS_MT_POSITION_X 000000b6
[ 83.887649] /dev/input/event3: EV_ABS ABS_MT_POSITION_Y 00000611
[ 83.887649] /dev/input/event3: EV_ABS ABS_MT_TOUCH_MAJOR 00000038
[ 83.887649] /dev/input/event3: EV_SYN SYN_REPORT 00000000 rate 121
可以滑动看报点是否正常,以及滑动看rate加速度是否平稳。
- systrace来看:
iq
: 描述system_server中 InputReader读取事件
aq
: 描述应用端获取事件
报点异常主要看iq,看一次down move(N) up 的流程是否顺畅,(当然tp报点也有优化,在相同位置是不报的),这个就看经验了朋友,一般来说机械手测量相对比较稳定,容易看出差异。
二、 Input耗时
一次用户输入事件的传递过程可以描述为: 硬件 -> kernel -> system_server -> app
简化出5个时间点:
- T1 表示 硬件中断的时间
- T2 表示 InputReader 从 /dev/input/xxx 读出事件的时间(InputReader读取事件的时候对事件打上时间戳)
- T3 表示 InputDispatcher 向 app 进程发送事件的时间
- T4 表示 app 主线程开始处理输入事件的时间
- T5 表示 app 主线程完成处理输入事件的时间
这个流程主要耗时点简单两个部分:(T1-T2这个阶段主要与底层报点相关,参考第一点)
system_server 耗时: T3 - T2
frameworks/native/libs/input/InputTransport.cpp
status_t InputPublisher::publishKeyEvent(...){
currentTime - eventTime
return mChannel->sendMessage(&msg);
}
这里是InputDispatcher与窗口建立connection之后,准备发送消息了,可以在这里增加日志打点,通过统计InputReader读取事件的时候对事件打上时间戳 与 执行当前方法的currentTime做对比,可以得知input时间在system_server处理过程中是否耗时。
应用处理耗时: T5 - T4
app端是通过InputEventReceiver来接收消息的,
开始分发的起点函数:
private void dispatchInputEvent(...){
记录startTime
}
log示例:
03-26 18:25:06.590 1306 1773 W InputTransport: Slow Input: 372ms so far, channel '3908d6b NavigationBar (server)' publisher ~ publishMotionEvent: seq=3004, deviceId=6, source=0x1002, action=0x2, actionButton=0x00000000, flags=0x0, edgeFlags=0x0, metaState=0x0, buttonState=0x0, xOffset=0.000000, yOffset=-2210.000000, xPrecision=1.000000, yPrecision=1.000000, downTime=28011572008000, eventTime=28011595886000, pointerCount=1
分发结束的终点函数:
public final void finishInputEvent(...){
currentTime - startTime
}
log示例:
03-22 11:04:07.692 7001 7001 W InputEventReceiver: App Input: Dispatching InputEvent took 114ms in main thread! (MotionEvent: event_seq=239, seq=7, action=ACTION_UP)
由此可以知道Input事件是否在应用端分发耗时。
三、 Input ANR
Input在本次input event处理耗时的情况下本身是不会触发ANR检查的,需要下一个input分发才会开始计算ANR超时。
Input ANR的原理与分析方法可以参考我之前的文章:
原理:Android Input(八)- ANR原理分析
分析方法:ANR问题分析
最后做个实战调试:
通过一个motion event的log打印来看下anr流程,开打InputDispatcher.cpp DEBUG_FOCUS开关,这里除了有系统log,我自己也加了点log。
写了个app, MainActivity中Button onClick直接睡眠足够长时间。
ANR发生:
从inBoundQueue取出一个事件:
07-25 19:37:48.760 1517 2010 D InputDispatcher: InputTest: dequeueAtHead
重置ANR Timeout时间
07-25 19:37:48.760 1517 2010 D InputDispatcher: Resetting ANR timeouts.
执行InputDispatcher::handleTargetsNotReadyLocked
对应reason触发的条件:
!connection->waitQueue.isEmpty() && currentTime >= connection->waitQueue.head->deliveryTime+ STREAM_AHEAD_EVENT_TIMEOUT(500ms)
翻译过来是waitQueue不为空,就是之前事件传递到应用端还没有callback回来,且等待队头时间超时500ms,这就意味着无法及时与focus window建立connection连接,开始触发ANR时间统计。
07-25 19:37:48.760 1517 2010 D InputDispatcher: Waiting for application to become ready for input: Window{e347a9 u0 com.stan.perfdemo/com.stan.perfdemo.MainActivity}. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 6069.2ms.
反复执行InputDispatcher::findTouchedWindowTargetsLocked,此时对应的mPendingEvent != NULL,那么无法重置ANR Timeout
07-25 19:37:48.760 1517 2010 D InputDispatcher: findTouchedWindow finished: injectionResult=-1, injectionPermission=1, timeSpentWaitingForApplication=0.0ms
07-25 19:37:48.761 1517 2010 D InputDispatcher: InputTest: (mPendingEvent != NULL)=1
07-25 19:37:48.761 1517 2010 D InputDispatcher: findTouchedWindow finished: injectionResult=-1, injectionPermission=1, timeSpentWaitingForApplication=1.3ms
07-25 19:37:48.763 735 826 E ANDR-PERF-MPCTL: Invalid profile no. 0, total profiles 0 only
07-25 19:37:48.853 1517 2010 D InputDispatcher: InputTest: (mPendingEvent != NULL)=1
07-25 19:37:48.854 1517 2010 D InputDispatcher: findTouchedWindow finished: injectionResult=-1, injectionPermission=1, timeSpentWaitingForApplication=93.9ms
...
07-25 19:37:56.770 1517 2010 D InputDispatcher: InputTest: (mPendingEvent != NULL)=1
满足ANR触发时间
07-25 19:37:56.770 1517 2010 D InputDispatcher: InputTest: onANRLocked : currentTime - mInputTargetWaitTimeoutTime=10341423
InputDispatcher::onANRLocked方法的打印,开始走ANR流程
07-25 19:37:56.770 1517 2010 I InputDispatcher: Application is not responding: Window{e347a9 u0 com.stan.perfdemo/com.stan.perfdemo.MainActivity}. It has been 8013.3ms since event, 8010.3ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 14079.5ms.
07-25 19:37:56.772 1517 2010 D InputDispatcher: findTouchedWindow finished: injectionResult=-1, injectionPermission=1, timeSpentWaitingForApplication=8010.3ms
然后这里会生成doNotifyANRLockedInterruptible加入commandQueue中,下次执行InputDispatcher::dispatchOnce 时候,先执行command
...
InputMonitor.java 执行notifyANR方法的打印
07-25 19:37:56.773 1517 2010 I WindowManager: Input event dispatching timed out sending to com.stan.perfdemo/com.stan.perfdemo.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 14079.5ms.
...
开始AMS执行anr流程dump trace以及弹窗提示并打印ANR log信息
07-25 19:38:00.302 1517 1534 E ActivityManager: ANR in com.stan.perfdemo (com.stan.perfdemo/.MainActivity)
07-25 19:38:00.302 1517 1534 E ActivityManager: PID: 7118
07-25 19:38:00.302 1517 1534 E ActivityManager: Reason: Input dispatching timed out (com.stan.perfdemo/com.stan.perfdemo.MainActivity, Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 14079.5ms.)
07-25 19:38:00.302 1517 1534 E ActivityManager: Load: 0.64 / 0.23 / 0.12
07-25 19:38:00.302 1517 1534 E ActivityManager: CPU usage from 15975ms to 0ms ago (2019-07-25 19:37:40.864 to 2019-07-25 19:37:56.839):
07-25 19:38:00.302 1517 1534 E ActivityManager: 2.6% 1517/system_server: 1.7% user + 0.8% kernel / faults: 907 minor