记Android12上一个原生bug引起的system

记Android12上一个原生bug引起的system_server crash

欢迎使用Markdown编辑器

一. 现象描述

近日测试上报一个几乎必现的crash，描述如下:
现象: launcher编辑状态与锁屏解锁交互时系统概率性重启
操作步骤:

进入launcher组件编辑状态
按电源键灭屏后亮屏，锁屏界面上滑解锁
launcher编辑状态向右或向左滑动
重复1，2，3 步骤多次操作，观察系统重启情况

二. 初步分析

随后在提供的日志中搜索“crash”，果然发现了以下的报错信息打印：

从日志中大概能分析出3点重要的信息

crash 发生在system_server进程
报错打印是Could not find consume time for seq=3513
crash大概发生在input时间在被client端处理完毕后向 inputdispatchar 发送 finsh的阶段

在这里插入图片描述
除此之外，在大概5s后，crash进一步引起了anr，根据anr的提示信息：** ANR in gesture monitor owned by pid:1045. Reason: PointerEventDispatcher0** 可进一步推断，**crash发生在手势处理的过程中向 inputdispatchar 发送 finsh的阶段
**
在这里插入图片描述

三. 分析crash发生的原因

猜想1

根据报错的提示信息和堆栈打印，在结合代码，报错发生在frameworks/native/libs/input/InputTransport.cpp中
在这里插入图片描述

上文提到发生crash发生在手势处理的过程中向 inputdispatchar 发送 finsh的阶段，大概流程如下

client端梳理完事件代用finishInputEvent随后进一步来到图中1的位置，
根据seq在容器mConsumeTimes中尝试获取一个时间戳
向input端发送finish消息
从容器mConsumeTimes中移除该seq对应的对象

crash发生在阶段2，从容器mConsumeTime获取不到该seq对应的对象，然后报错 Could not find consume time for seq=3513，然后根据该类的其他代码得知，mConsumeTime 是一个map类型的容器，在事件分发前，会以事件的seq为key，当前时间为value添加一条记录，当时间被client端处理完毕后然后从该容器中移除对应seq的记录。
在这里插入图片描述
结合代码和报错的注释，初步猜想是对应事件的finish调用了两次引发了crash：

为了验证猜想，随后放开了input相关的日志，进行复现，发现发生crash时对应seq的事件确实调用了两次finish：

猜想是正确的，现在的问题变成了为什么status_t InputConsumer::sendFinishedSignal发生了两次，

进一步猜想

进一步阅读代码得知frameworks/base/core/jni/android_view_InputEventReceiver.cpp中会调用到 InputConsumer::sendFinishedSigna.
对于普通的touch事件来说,调用到InputConsumer::sendFinishedSigna.有两种情况：

情况1
事件被java层的frameworks/base/core/java/android/view/InputEventReceiver.java正常处理完毕后，主动调用finishInputEvent随后再来到natvie层调用到 InputConsumer::sendFinishedSigna. 如下图
情况二
在时间分发阶段，构造了一个java层的事件对象，然后交给java层去处理，java层处理阶段出现了异常，native层的NativeInputEventReceiver捕获到了该异常，NativeInputEventReceiver会发起一次InputConsumer.sendFinishedSignal

status_t NativeInputEventReceiver::consumeEvents(JNIEnv* env,bool consumeBatches, nsecs_t frameTime, bool* outConsumedBatch) {.......bool skipCallbacks = false;for (;;) {uint32_t seq;........jobject inputEventObj;switch (inputEvent->getType()) {// 构造 MotionEvent 对象case AINPUT_EVENT_TYPE_MOTION: {if (kDebugDispatchCycle) {ALOGD("channel '%s' ~ Received motion event.", getInputChannelName().c_str());}MotionEvent* motionEvent = static_cast<MotionEvent*>(inputEvent);if ((motionEvent->getAction() & AMOTION_EVENT_ACTION_MOVE) && outConsumedBatch) {*outConsumedBatch = true;}inputEventObj = android_view_MotionEvent_obtainAsCopy(env, motionEvent);break;}........default:assert(false); // InputConsumer should prevent this from ever happeninginputEventObj = nullptr;}if (inputEventObj) {if (kDebugDispatchCycle) {ALOGD("channel '%s' ~ Dispatching input event.", getInputChannelName().c_str());}env->CallVoidMethod(receiverObj.get(),// 调用java方法，分发事件gInputEventReceiverClassInfo.dispatchInputEvent, seq, inputEventObj);if (env->ExceptionCheck()) {// 捕获到java层的异常，使得skipCallbacks = true;ALOGE("Exception dispatching input event.");skipCallbacks = true;}env->DeleteLocalRef(inputEventObj);} else {ALOGW("channel '%s' ~ Failed to obtain event object.",getInputChannelName().c_str());skipCallbacks = true;}}if (skipCallbacks) {ALOGD("NativeInputEventReceiver consumeEvents seq=%u ", seq);// 因为前面捕获到异常，skipCallbacks == ture。 调用mInputConsumer.sendFinishedSignalmInputConsumer.sendFinishedSignal(seq, false);}}
}

在上文两处中添加log，复现crash log如下：
在这里插入图片描述

可见对于seq 3513 ，正常情况和发生异常的情况都调用了一次InputConsumer.sendFinishedSignal！！！

总结一下目前的线索：在桌面手势分发seq == 3513的事件阶段出现了异常，异常被native层的NativeInputEventReceiver得知，然后发起了一次sendFinishedSignal，同时java层在对seq ==3513事件处理结束后，主动调用了一次sendFinishedSignal，两次调用sendFinishedSignal进而引发crash。

有新的疑问涌出：

桌面手势分发seq == 3513的事件阶段出现了什么异常
为什么正常的情况和异常的情况都触发？

四. 发现端倪

在native检测到异常的分支里面添加对错误的打印，然后复现问题，发现如下打印，原来是上层发生可空指针问题
在这里插入图片描述
但，这个空指针问题怎么会使得异常分支和正常分支的sendFnishSignal都触发呢？随后在PointerEventDispatcher这个类中发现端倪：

frameworks/base/services/core/java/com/android/server/wm/PointerEventDispatcher.java
@Overridepublic void onInputEvent(InputEvent event) {try {if (event instanceof MotionEvent&& (event.getSource() & InputDevice.SOURCE_CLASS_POINTER) != 0) {MotionEvent motionEvent = (MotionEvent) event;if (ENABLE_PER_WINDOW_INPUT_ROTATION) {final int rotation = mDisplayContent.getRotation();if (rotation != Surface.ROTATION_0) {mDisplayContent.getDisplay().getRealSize(mTmpSize);motionEvent = MotionEvent.obtain(motionEvent);motionEvent.transform(MotionEvent.createRotateMatrix(rotation, mTmpSize.x, mTmpSize.y));}}PointerEventListener[] listeners;synchronized (mListeners) {if (mListenersArray == null) {mListenersArray = new PointerEventListener[mListeners.size()];mListeners.toArray(mListenersArray);}listeners = mListenersArray;}for (int i = 0; i < listeners.length; ++i) {listeners[i].onPointerEvent(motionEvent);}}} finally {  // catch呢？？？？？finishInputEvent(event, false);}}

如上，分发完事件后，无论是否发生异常都会在finally中调用finishInputEvent，同时虽然有try， final,但没有catch，这就意味着该段逻辑并未捕获任何类型的异常！！！！，真相大白：

为什么正常情况的sendFnishSignal会被触发？事件处理结束后触发了 finally 执行了finishInputEvent,随后进一步触发sendFnishSignal
为什么异常情况的sendFnishSignal也会被触发？首先事件分发阶段发生了异常，但PointerEventDispatcher并没有catch住相关的异常,随后异常被native层的NativeInputEventReceiver获知，进入了异常分支也触发了一次sendFnishSignal。

但，疑问还在继续，这似乎是google的原生的一个bug，为什么谷歌的代码这样处理？无论正常还是异常情况下 java层调用finishInputEvent 触发一次sendFnishSignal，然后native层检测到异常再触发一次 sendFnishSignal，Java层和native层的代码不像同一个人写的，都考虑到了异常情况要去触发sendFnishSignal，然后就发生了在分发阶段出现异常时同一事件就发生了两次 sendFnishSignal

这么明显的bug，谷歌应该能发现吧？果然：
在这里插入图片描述
谷歌的修复：发生异常时native层不再触发sendFnishSignal