Log windows that are being interacted with
If the list of windows being interacted with changes, log the new list
to event log.
Example logs:
06-08 15:47:55.349 4105 4181 I input_interaction: Interaction with windows: ee638df NotificationShade (server),
06-08 15:48:03.917 4105 4181 I input_interaction: Interaction with windows: 399b259 com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity (server),
06-08 15:48:10.844 4105 4181 I input_interaction: Interaction with windows: fcc1e60 com.android.systemui.ImageWallpaper (server), 399b259 com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity (server),
06-08 15:49:30.091 4105 4181 I input_interaction: Interaction with windows: ee638df NotificationShade (server),
06-08 15:49:31.757 4105 4181 I input_interaction: Interaction with windows: fcc1e60 com.android.systemui.ImageWallpaper (server), 399b259 com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity (server),
06-08 15:49:33.293 4105 4181 I input_interaction: Interaction with windows: <none>
Bug: 153092301
Test: adb logcat -b events | grep -i input
Change-Id: Ia4216beb200163e60e05374b6ea363412bff55f3
Merged-In: Ia4216beb200163e60e05374b6ea363412bff55f3
diff --git a/services/inputflinger/dispatcher/Android.bp b/services/inputflinger/dispatcher/Android.bp
index a98f4b4..b242eec 100644
--- a/services/inputflinger/dispatcher/Android.bp
+++ b/services/inputflinger/dispatcher/Android.bp
@@ -67,4 +67,5 @@
export_header_lib_headers: [
"libinputdispatcher_headers",
],
+ logtags: ["EventLogTags.logtags"],
}
diff --git a/services/inputflinger/dispatcher/EventLogTags.logtags b/services/inputflinger/dispatcher/EventLogTags.logtags
new file mode 100644
index 0000000..9c0f80e
--- /dev/null
+++ b/services/inputflinger/dispatcher/EventLogTags.logtags
@@ -0,0 +1,42 @@
+# The entries in this file map a sparse set of log tag numbers to tag names.
+# This is installed on the device, in /system/etc, and parsed by logcat.
+#
+# Tag numbers are decimal integers, from 0 to 2^31. (Let's leave the
+# negative values alone for now.)
+#
+# Tag names are one or more ASCII letters and numbers or underscores, i.e.
+# "[A-Z][a-z][0-9]_". Do not include spaces or punctuation (the former
+# impacts log readability, the latter makes regex searches more annoying).
+#
+# Tag numbers and names are separated by whitespace. Blank lines and lines
+# starting with '#' are ignored.
+#
+# Optionally, after the tag names can be put a description for the value(s)
+# of the tag. Description are in the format
+# (<name>|data type[|data unit])
+# Multiple values are separated by commas.
+#
+# The data type is a number from the following values:
+# 1: int
+# 2: long
+# 3: string
+# 4: list
+#
+# The data unit is a number taken from the following list:
+# 1: Number of objects
+# 2: Number of bytes
+# 3: Number of milliseconds
+# 4: Number of allocations
+# 5: Id
+# 6: Percent
+# Default value for data of type int/long is 2 (bytes).
+#
+# See system/core/logcat/event.logtags for the master copy of the tags.
+
+# 62000 - 62199 reserved for inputflinger
+
+62000 input_interaction (windows|4)
+62001 input_focus (window|3)
+
+# NOTE - the range 1000000-2000000 is reserved for partners and others who
+# want to define their own log tags without conflicting with the core platform.
\ No newline at end of file
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index 46f6f44..959eeea 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -62,6 +62,7 @@
#include <binder/Binder.h>
#include <input/InputDevice.h>
#include <log/log.h>
+#include <log/log_event_list.h>
#include <openssl/hmac.h>
#include <openssl/rand.h>
#include <powermanager/PowerManager.h>
@@ -104,6 +105,10 @@
// Number of recent events to keep for debugging purposes.
constexpr size_t RECENT_QUEUE_MAX_SIZE = 10;
+// Event log tags. See EventLogTags.logtags for reference
+constexpr int LOGTAG_INPUT_INTERACTION = 62000;
+constexpr int LOGTAG_INPUT_FOCUS = 62001;
+
static inline nsecs_t now() {
return systemTime(SYSTEM_TIME_MONOTONIC);
}
@@ -1028,7 +1033,9 @@
target.inputChannel = channel;
target.flags = InputTarget::FLAG_DISPATCH_AS_IS;
entry->dispatchInProgress = true;
-
+ std::string message = std::string("Focus ") + (entry->hasFocus ? "entering " : "leaving ") +
+ channel->getName();
+ android_log_event_list(LOGTAG_INPUT_FOCUS) << message << LOG_ID_EVENTS;
dispatchEventLocked(currentTime, entry, {target});
}
@@ -1266,6 +1273,8 @@
ALOGD("dispatchEventToCurrentInputTargets");
#endif
+ updateInteractionTokensLocked(*eventEntry, inputTargets);
+
ALOG_ASSERT(eventEntry->dispatchInProgress); // should already have been set to true
pokeUserActivityLocked(*eventEntry);
@@ -2417,6 +2426,73 @@
traceOutboundQueueLength(connection);
}
+/**
+ * This function is purely for debugging. It helps us understand where the user interaction
+ * was taking place. For example, if user is touching launcher, we will see a log that user
+ * started interacting with launcher. In that example, the event would go to the wallpaper as well.
+ * We will see both launcher and wallpaper in that list.
+ * Once the interaction with a particular set of connections starts, no new logs will be printed
+ * until the set of interacted connections changes.
+ *
+ * The following items are skipped, to reduce the logspam:
+ * ACTION_OUTSIDE: any windows that are receiving ACTION_OUTSIDE are not logged
+ * ACTION_UP: any windows that receive ACTION_UP are not logged (for both keys and motions).
+ * This includes situations like the soft BACK button key. When the user releases (lifts up the
+ * finger) the back button, then navigation bar will inject KEYCODE_BACK with ACTION_UP.
+ * Both of those ACTION_UP events would not be logged
+ * Monitors (both gesture and global): any gesture monitors or global monitors receiving events
+ * will not be logged. This is omitted to reduce the amount of data printed.
+ * If you see <none>, it's likely that one of the gesture monitors pilfered the event, and therefore
+ * gesture monitor is the only connection receiving the remainder of the gesture.
+ */
+void InputDispatcher::updateInteractionTokensLocked(const EventEntry& entry,
+ const std::vector<InputTarget>& targets) {
+ // Skip ACTION_UP events, and all events other than keys and motions
+ if (entry.type == EventEntry::Type::KEY) {
+ const KeyEntry& keyEntry = static_cast<const KeyEntry&>(entry);
+ if (keyEntry.action == AKEY_EVENT_ACTION_UP) {
+ return;
+ }
+ } else if (entry.type == EventEntry::Type::MOTION) {
+ const MotionEntry& motionEntry = static_cast<const MotionEntry&>(entry);
+ if (motionEntry.action == AMOTION_EVENT_ACTION_UP) {
+ return;
+ }
+ } else {
+ return; // Not a key or a motion
+ }
+
+ std::unordered_set<sp<IBinder>, IBinderHash> newConnections;
+ for (const InputTarget& target : targets) {
+ if ((target.flags & InputTarget::FLAG_DISPATCH_AS_OUTSIDE) ==
+ InputTarget::FLAG_DISPATCH_AS_OUTSIDE) {
+ continue; // Skip windows that receive ACTION_OUTSIDE
+ }
+
+ sp<IBinder> token = target.inputChannel->getConnectionToken();
+ sp<Connection> connection = getConnectionLocked(token); // get connection
+ if (connection->monitor) {
+ continue; // We only need to keep track of the non-monitor connections.
+ }
+
+ newConnections.insert(std::move(token));
+ }
+ if (newConnections == mInteractionConnections) {
+ return; // no change
+ }
+ mInteractionConnections = newConnections;
+ std::string windowList;
+ for (const sp<IBinder>& token : newConnections) {
+ sp<Connection> connection = getConnectionLocked(token);
+ windowList += connection->getWindowName() + ", ";
+ }
+ std::string message = "Interaction with windows: " + windowList;
+ if (windowList.empty()) {
+ message += "<none>";
+ }
+ android_log_event_list(LOGTAG_INPUT_INTERACTION) << message << LOG_ID_EVENTS;
+}
+
void InputDispatcher::dispatchPointerDownOutsideFocus(uint32_t source, int32_t action,
const sp<IBinder>& newToken) {
int32_t maskedAction = action & AMOTION_EVENT_ACTION_MASK;
diff --git a/services/inputflinger/dispatcher/InputDispatcher.h b/services/inputflinger/dispatcher/InputDispatcher.h
index 0c3ea36..1980435 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.h
+++ b/services/inputflinger/dispatcher/InputDispatcher.h
@@ -48,6 +48,7 @@
#include <deque>
#include <optional>
#include <unordered_map>
+#include <unordered_set>
#include <InputListener.h>
#include <InputReporterInterface.h>
@@ -323,6 +324,11 @@
// Dispatcher state at time of last ANR.
std::string mLastAnrState GUARDED_BY(mLock);
+ // The connection token of the channel that was last interacted with.
+ std::unordered_set<sp<IBinder>, IBinderHash> mInteractionConnections GUARDED_BY(mLock);
+ void updateInteractionTokensLocked(const EventEntry& entry,
+ const std::vector<InputTarget>& targets) REQUIRES(mLock);
+
// Dispatch inbound events.
bool dispatchConfigurationChangedLocked(nsecs_t currentTime, ConfigurationChangedEntry* entry)
REQUIRES(mLock);