From ffb497743831ae4857b674629b58ea3c46d01431 Mon Sep 17 00:00:00 2001 From: Jeff Brown Date: Fri, 10 Oct 2014 19:01:34 -0700 Subject: [PATCH] Improve ANR diagnostics. Print more details about the exact reason that an ANR has occurred. Also start checking that the window actually has a registered input connection that is not in a broken state. These windows are supposed to be cleaned up by the window manager promptly as if the app had crashed but the pattern of ANRs we are observing suggests that broken windows might be sticking around longer than they should. Bug: 17721767 Change-Id: Ie2803a3fa9642381ecadc198fec15e1b70d93c20 --- services/inputflinger/InputDispatcher.cpp | 116 +++++++++++++--------- services/inputflinger/InputDispatcher.h | 6 +- 2 files changed, 71 insertions(+), 51 deletions(-) diff --git a/services/inputflinger/InputDispatcher.cpp b/services/inputflinger/InputDispatcher.cpp index 2b5e74446..02fb6f04d 100644 --- a/services/inputflinger/InputDispatcher.cpp +++ b/services/inputflinger/InputDispatcher.cpp @@ -1064,6 +1064,7 @@ void InputDispatcher::resetANRTimeoutsLocked() { int32_t InputDispatcher::findFocusedWindowTargetsLocked(nsecs_t currentTime, const EventEntry* entry, Vector& inputTargets, nsecs_t* nextWakeupTime) { int32_t injectionResult; + String8 reason; // If there is no currently focused window and no focused application // then drop the event. @@ -1088,20 +1089,12 @@ int32_t InputDispatcher::findFocusedWindowTargetsLocked(nsecs_t currentTime, goto Failed; } - // If the currently focused window is paused then keep waiting. - if (mFocusedWindowHandle->getInfo()->paused) { + // Check whether the window is ready for more input. + reason = checkWindowReadyForMoreInputLocked(currentTime, + mFocusedWindowHandle, entry, "focused"); + if (!reason.isEmpty()) { injectionResult = handleTargetsNotReadyLocked(currentTime, entry, - mFocusedApplicationHandle, mFocusedWindowHandle, nextWakeupTime, - "Waiting because the focused window is paused."); - goto Unresponsive; - } - - // If the currently focused window is still working on previous events then keep waiting. - if (!isWindowReadyForMoreInputLocked(currentTime, mFocusedWindowHandle, entry)) { - injectionResult = handleTargetsNotReadyLocked(currentTime, entry, - mFocusedApplicationHandle, mFocusedWindowHandle, nextWakeupTime, - "Waiting because the focused window has not finished " - "processing the input events that were previously delivered to it."); + mFocusedApplicationHandle, mFocusedWindowHandle, nextWakeupTime, reason.string()); goto Unresponsive; } @@ -1426,20 +1419,12 @@ int32_t InputDispatcher::findTouchedWindowTargetsLocked(nsecs_t currentTime, for (size_t i = 0; i < mTempTouchState.windows.size(); i++) { const TouchedWindow& touchedWindow = mTempTouchState.windows[i]; if (touchedWindow.targetFlags & InputTarget::FLAG_FOREGROUND) { - // If the touched window is paused then keep waiting. - if (touchedWindow.windowHandle->getInfo()->paused) { + // Check whether the window is ready for more input. + String8 reason = checkWindowReadyForMoreInputLocked(currentTime, + touchedWindow.windowHandle, entry, "touched"); + if (!reason.isEmpty()) { injectionResult = handleTargetsNotReadyLocked(currentTime, entry, - NULL, touchedWindow.windowHandle, nextWakeupTime, - "Waiting because the touched window is paused."); - goto Unresponsive; - } - - // If the touched window is still working on previous events then keep waiting. - if (!isWindowReadyForMoreInputLocked(currentTime, touchedWindow.windowHandle, entry)) { - injectionResult = handleTargetsNotReadyLocked(currentTime, entry, - NULL, touchedWindow.windowHandle, nextWakeupTime, - "Waiting because the touched window has not finished " - "processing the input events that were previously delivered to it."); + NULL, touchedWindow.windowHandle, nextWakeupTime, reason.string()); goto Unresponsive; } } @@ -1657,29 +1642,57 @@ bool InputDispatcher::isWindowObscuredAtPointLocked( return false; } -bool InputDispatcher::isWindowReadyForMoreInputLocked(nsecs_t currentTime, - const sp& windowHandle, const EventEntry* eventEntry) { +String8 InputDispatcher::checkWindowReadyForMoreInputLocked(nsecs_t currentTime, + const sp& windowHandle, const EventEntry* eventEntry, + const char* targetType) { + // If the window is paused then keep waiting. + if (windowHandle->getInfo()->paused) { + return String8::format("Waiting because the %s window is paused.", targetType); + } + + // If the window's connection is not registered then keep waiting. ssize_t connectionIndex = getConnectionIndexLocked(windowHandle->getInputChannel()); - if (connectionIndex >= 0) { - sp connection = mConnectionsByFd.valueAt(connectionIndex); - if (connection->inputPublisherBlocked) { - return false; - } - if (eventEntry->type == EventEntry::TYPE_KEY) { - // If the event is a key event, then we must wait for all previous events to - // complete before delivering it because previous events may have the - // side-effect of transferring focus to a different window and we want to - // ensure that the following keys are sent to the new window. - // - // Suppose the user touches a button in a window then immediately presses "A". - // If the button causes a pop-up window to appear then we want to ensure that - // the "A" key is delivered to the new pop-up window. This is because users - // often anticipate pending UI changes when typing on a keyboard. - // To obtain this behavior, we must serialize key events with respect to all - // prior input events. - return connection->outboundQueue.isEmpty() - && connection->waitQueue.isEmpty(); + if (connectionIndex < 0) { + return String8::format("Waiting because the %s window's input channel is not " + "registered with the input dispatcher. The window may be in the process " + "of being removed.", targetType); + } + + // If the connection is dead then keep waiting. + sp connection = mConnectionsByFd.valueAt(connectionIndex); + if (connection->status != Connection::STATUS_NORMAL) { + return String8::format("Waiting because the %s window's input connection is %s." + "The window may be in the process of being removed.", targetType, + connection->getStatusLabel()); + } + + // If the connection is backed up then keep waiting. + if (connection->inputPublisherBlocked) { + return String8::format("Waiting because the %s window's input channel is full. " + "Outbound queue length: %d. Wait queue length: %d.", + targetType, connection->outboundQueue.count(), connection->waitQueue.count()); + } + + // Ensure that the dispatch queues aren't too far backed up for this event. + if (eventEntry->type == EventEntry::TYPE_KEY) { + // If the event is a key event, then we must wait for all previous events to + // complete before delivering it because previous events may have the + // side-effect of transferring focus to a different window and we want to + // ensure that the following keys are sent to the new window. + // + // Suppose the user touches a button in a window then immediately presses "A". + // If the button causes a pop-up window to appear then we want to ensure that + // the "A" key is delivered to the new pop-up window. This is because users + // often anticipate pending UI changes when typing on a keyboard. + // To obtain this behavior, we must serialize key events with respect to all + // prior input events. + if (!connection->outboundQueue.isEmpty() || !connection->waitQueue.isEmpty()) { + return String8::format("Waiting to send key event because the %s window has not " + "finished processing all of the input events that were previously " + "delivered to it. Outbound queue length: %d. Wait queue length: %d.", + targetType, connection->outboundQueue.count(), connection->waitQueue.count()); } + } else { // Touch events can always be sent to a window immediately because the user intended // to touch whatever was visible at the time. Even if focus changes or a new // window appears moments later, the touch event was meant to be delivered to @@ -1698,10 +1711,15 @@ bool InputDispatcher::isWindowReadyForMoreInputLocked(nsecs_t currentTime, if (!connection->waitQueue.isEmpty() && currentTime >= connection->waitQueue.head->deliveryTime + STREAM_AHEAD_EVENT_TIMEOUT) { - return false; + return String8::format("Waiting to send non-key event because the %s window has not " + "finished processing certain input events that were delivered to it over " + "%0.1fms ago. Wait queue length: %d. Wait queue head age: %0.1fms.", + targetType, STREAM_AHEAD_EVENT_TIMEOUT * 0.000001f, + connection->waitQueue.count(), + (currentTime - connection->waitQueue.head->deliveryTime) * 0.000001f); } } - return true; + return String8::empty(); } String8 InputDispatcher::getApplicationWindowLabelLocked( diff --git a/services/inputflinger/InputDispatcher.h b/services/inputflinger/InputDispatcher.h index 0d15d7b27..70b0a34b0 100644 --- a/services/inputflinger/InputDispatcher.h +++ b/services/inputflinger/InputDispatcher.h @@ -1038,11 +1038,13 @@ private: const InjectionState* injectionState); bool isWindowObscuredAtPointLocked(const sp& windowHandle, int32_t x, int32_t y) const; - bool isWindowReadyForMoreInputLocked(nsecs_t currentTime, - const sp& windowHandle, const EventEntry* eventEntry); String8 getApplicationWindowLabelLocked(const sp& applicationHandle, const sp& windowHandle); + String8 checkWindowReadyForMoreInputLocked(nsecs_t currentTime, + const sp& windowHandle, const EventEntry* eventEntry, + const char* targetType); + // Manage the dispatch cycle for a single connection. // These methods are deliberately not Interruptible because doing all of the work // with the mutex held makes it easier to ensure that connection invariants are maintained.