Dynamic logs for motions in UnwantedInteractionBlocker
Currently, we have no way to debug the palm rejection operation in real
time. On some devices, we are observing touches rejected unreasonably.
For improved debugging, provide a way to turn on the logs at runtime.
Sample logs:
07-29 20:50:51.938 21364 21461 D UnwantedInteractionBlocker: notifyMotion: NotifyMotionArgs(id=437279320, eventTime=681206765436000, deviceId=4, source=TOUCHSCREEN, action=MOVE, pointerCount=2 pointers={0: id=0 x=1998.0 y=732.0 pressure=1.0 major=78.0 minor=78.0 orientation=1.6}, {1: id=1 x=1651.0 y=705.0 pressure=0.5 major=14.0 minor=14.0 orientation=1.6}, flags=0x00000000)
07-29 20:50:51.939 21364 21461 D UnwantedInteractionBlocker: Filter: touches = 0 : InProgressTouchEvdev(x=1998, y=732, tracking_id=0, slot=0, pressure=0.996094, major=78, minor=78, tool_type=0, altered=1, was_touching=1, touching=1)
07-29 20:50:51.939 21364 21461 D UnwantedInteractionBlocker: 1 : InProgressTouchEvdev(x=1651, y=705, tracking_id=1, slot=1, pressure=0.546875, major=14, minor=14, tool_type=0, altered=1, was_touching=1, touching=1)
07-29 20:50:51.939 21364 21461 D UnwantedInteractionBlocker: Response: slotsToHold = 00000000000000000000, slotsToSuppress = 00000000000000000011
07-29 20:50:51.939 21364 21461 I UnwantedInteractionBlocker: Palm detected, removing pointer ids {0, 1} after 656ms from NotifyMotionArgs(id=437279320, eventTime=681206765436000, deviceId=4, source=TOUCHSCREEN, action=MOVE, pointerCount=2 pointers={0: id=0 x=1998.0 y=732.0 pressure=1.0 major=78.0 minor=78.0 orientation=1.6}, {1: id=1 x=1651.0 y=705.0 pressure=0.5 major=14.0 minor=14.0 orientation=1.6}, flags=0x00000000)
07-29 20:50:51.939 21364 21461 D UnwantedInteractionBlocker: enqueueOutboundMotionLocked: NotifyMotionArgs(id=437279320, eventTime=681206765436000, deviceId=4, source=TOUCHSCREEN, action=CANCEL, pointerCount=1 pointers={0: id=1 x=1651.0 y=705.0 pressure=0.5 major=14.0 minor=14.0 orientation=1.6}, flags=0x00000020)
07-29 20:50:51.947 21364 21461 D UnwantedInteractionBlocker: notifyMotion: NotifyMotionArgs(id=1057496278, eventTime=681206774728000, deviceId=4, source=TOUCHSCREEN, action=MOVE, pointerCount=2 pointers={0: id=0 x=1996.0 y=732.0 pressure=1.0 major=78.0 minor=78.0 orientation=1.6}, {1: id=1 x=1651.0 y=705.0 pressure=0.5 major=14.0 minor=14.0 orientation=1.6}, flags=0x00000000)
07-29 20:50:51.947 21364 21461 D UnwantedInteractionBlocker: Filter: touches = 0 : InProgressTouchEvdev(x=1996, y=732, tracking_id=0, slot=0, pressure=0.996094, major=78, minor=78, tool_type=0, altered=1, was_touching=1, touching=1)
07-29 20:50:51.947 21364 21461 D UnwantedInteractionBlocker: 1 : InProgressTouchEvdev(x=1651, y=705, tracking_id=1, slot=1, pressure=0.542969, major=14, minor=14, tool_type=0, altered=1, was_touching=1, touching=1)
07-29 20:50:51.948 21364 21461 D UnwantedInteractionBlocker: Response: slotsToHold = 00000000000000000000, slotsToSuppress = 00000000000000000011
Bug: 239463037
Bug: 198472780
Test: looked at the logs with palm rejection enabled
Change-Id: I10e54bd0c4ca26fd6197b3ff0069f9799ea91ccf
diff --git a/include/input/Input.h b/include/input/Input.h
index e7d68fc..7ea2970 100644
--- a/include/input/Input.h
+++ b/include/input/Input.h
@@ -297,6 +297,8 @@
*/
const char* motionClassificationToString(MotionClassification classification);
+const char* motionToolTypeToString(int32_t toolType);
+
/**
* Portion of FrameMetrics timeline of interest to input code.
*/
diff --git a/libs/input/Input.cpp b/libs/input/Input.cpp
index 375b684..155cb04 100644
--- a/libs/input/Input.cpp
+++ b/libs/input/Input.cpp
@@ -90,6 +90,25 @@
}
}
+const char* motionToolTypeToString(int32_t toolType) {
+ switch (toolType) {
+ case AMOTION_EVENT_TOOL_TYPE_UNKNOWN:
+ return "UNKNOWN";
+ case AMOTION_EVENT_TOOL_TYPE_FINGER:
+ return "FINGER";
+ case AMOTION_EVENT_TOOL_TYPE_STYLUS:
+ return "STYLUS";
+ case AMOTION_EVENT_TOOL_TYPE_MOUSE:
+ return "MOUSE";
+ case AMOTION_EVENT_TOOL_TYPE_ERASER:
+ return "ERASER";
+ case AMOTION_EVENT_TOOL_TYPE_PALM:
+ return "PALM";
+ default:
+ return "INVALID";
+ }
+}
+
// --- IdGenerator ---
IdGenerator::IdGenerator(Source source) : mSource(source) {}
diff --git a/services/inputflinger/InputListener.cpp b/services/inputflinger/InputListener.cpp
index 2a3924b..dce327e 100644
--- a/services/inputflinger/InputListener.cpp
+++ b/services/inputflinger/InputListener.cpp
@@ -196,9 +196,20 @@
}
coords += StringPrintf("{%" PRIu32 ": ", i);
coords +=
- StringPrintf("id=%" PRIu32 " x=%.1f y=%.1f, pressure=%.1f", pointerProperties[i].id,
+ StringPrintf("id=%" PRIu32 " x=%.1f y=%.1f pressure=%.1f", pointerProperties[i].id,
pointerCoords[i].getX(), pointerCoords[i].getY(),
pointerCoords[i].getAxisValue(AMOTION_EVENT_AXIS_PRESSURE));
+ const int32_t toolType = pointerProperties[i].toolType;
+ if (toolType != AMOTION_EVENT_TOOL_TYPE_FINGER) {
+ coords += StringPrintf(" toolType=%s", motionToolTypeToString(toolType));
+ }
+ const float major = pointerCoords[i].getAxisValue(AMOTION_EVENT_AXIS_TOUCH_MAJOR);
+ const float minor = pointerCoords[i].getAxisValue(AMOTION_EVENT_AXIS_TOUCH_MINOR);
+ const float orientation = pointerCoords[i].getAxisValue(AMOTION_EVENT_AXIS_ORIENTATION);
+ if (major != 0 || minor != 0) {
+ coords += StringPrintf(" major=%.1f minor=%.1f orientation=%.1f", major, minor,
+ orientation);
+ }
coords += "}";
}
return StringPrintf("NotifyMotionArgs(id=%" PRId32 ", eventTime=%" PRId64 ", deviceId=%" PRId32
diff --git a/services/inputflinger/UnwantedInteractionBlocker.cpp b/services/inputflinger/UnwantedInteractionBlocker.cpp
index 2193b7c..4744db0 100644
--- a/services/inputflinger/UnwantedInteractionBlocker.cpp
+++ b/services/inputflinger/UnwantedInteractionBlocker.cpp
@@ -39,6 +39,30 @@
namespace android {
+/**
+ * Log detailed debug messages about each inbound motion event notification to the blocker.
+ * Enable this via "adb shell setprop log.tag.UnwantedInteractionBlockerInboundMotion DEBUG"
+ * (requires restart)
+ */
+const bool DEBUG_INBOUND_MOTION =
+ __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "InboundMotion", ANDROID_LOG_INFO);
+
+/**
+ * Log detailed debug messages about each outbound motion event processed by the blocker.
+ * Enable this via "adb shell setprop log.tag.UnwantedInteractionBlockerOutboundMotion DEBUG"
+ * (requires restart)
+ */
+const bool DEBUG_OUTBOUND_MOTION =
+ __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "OutboundMotion", ANDROID_LOG_INFO);
+
+/**
+ * Log the data sent to the model and received back from the model.
+ * Enable this via "adb shell setprop log.tag.UnwantedInteractionBlockerModel DEBUG"
+ * (requires restart)
+ */
+const bool DEBUG_MODEL =
+ __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "Model", ANDROID_LOG_INFO);
+
// Category (=namespace) name for the input settings that are applied at boot time
static const char* INPUT_NATIVE_BOOT = "input_native_boot";
/**
@@ -309,6 +333,7 @@
}
void UnwantedInteractionBlocker::notifyMotion(const NotifyMotionArgs* args) {
+ ALOGD_IF(DEBUG_INBOUND_MOTION, "%s: %s", __func__, args->dump().c_str());
{ // acquire lock
std::scoped_lock lock(mLock);
const std::vector<NotifyMotionArgs> processedArgs =
@@ -322,17 +347,22 @@
mQueuedListener.flush();
}
+void UnwantedInteractionBlocker::enqueueOutboundMotionLocked(const NotifyMotionArgs& args) {
+ ALOGD_IF(DEBUG_OUTBOUND_MOTION, "%s: %s", __func__, args.dump().c_str());
+ mQueuedListener.notifyMotion(&args);
+}
+
void UnwantedInteractionBlocker::notifyMotionLocked(const NotifyMotionArgs* args) {
auto it = mPalmRejectors.find(args->deviceId);
const bool sendToPalmRejector = it != mPalmRejectors.end() && isFromTouchscreen(args->source);
if (!sendToPalmRejector) {
- mQueuedListener.notifyMotion(args);
+ enqueueOutboundMotionLocked(*args);
return;
}
std::vector<NotifyMotionArgs> processedArgs = it->second.processMotion(*args);
for (const NotifyMotionArgs& loopArgs : processedArgs) {
- mQueuedListener.notifyMotion(&loopArgs);
+ enqueueOutboundMotionLocked(loopArgs);
}
}
@@ -616,8 +646,18 @@
getTouches(args, mDeviceInfo, oldSlotState, mSlotState);
::base::TimeTicks chromeTimestamp = toChromeTimestamp(args.eventTime);
+ if (DEBUG_MODEL) {
+ std::stringstream touchesStream;
+ for (const ::ui::InProgressTouchEvdev& touch : touches) {
+ touchesStream << touch.tracking_id << " : " << touch << "\n";
+ }
+ ALOGD("Filter: touches = %s", touchesStream.str().c_str());
+ }
mPalmDetectionFilter->Filter(touches, chromeTimestamp, &slotsToHold, &slotsToSuppress);
+ ALOGD_IF(DEBUG_MODEL, "Response: slotsToHold = %s, slotsToSuppress = %s",
+ slotsToHold.to_string().c_str(), slotsToSuppress.to_string().c_str());
+
// Now that we know which slots should be suppressed, let's convert those to pointer id's.
std::set<int32_t> oldSuppressedIds;
std::swap(oldSuppressedIds, mSuppressedPointerIds);
diff --git a/services/inputflinger/UnwantedInteractionBlocker.h b/services/inputflinger/UnwantedInteractionBlocker.h
index a433764..8ff9658 100644
--- a/services/inputflinger/UnwantedInteractionBlocker.h
+++ b/services/inputflinger/UnwantedInteractionBlocker.h
@@ -101,6 +101,9 @@
std::map<int32_t /*deviceId*/, PalmRejector> mPalmRejectors GUARDED_BY(mLock);
// TODO(b/210159205): delete this when simultaneous stylus and touch is supported
void notifyMotionLocked(const NotifyMotionArgs* args) REQUIRES(mLock);
+
+ // Call this function for outbound events so that they can be logged when logging is enabled.
+ void enqueueOutboundMotionLocked(const NotifyMotionArgs& args) REQUIRES(mLock);
};
class SlotState {