Allow debug logging of dispatcher's inbound events to be enabled on the fly
Enabling debug logs via adb commands required a reboot of the shell. In
order to debug flaky tests more easily, we allow raw event logs to be
enabled and disabled without the need for a restart on debuggable
builds.
We limit this ability to debuggable builds ensure there is no
performance overhead on user builds.
This change allows us to enable more verbose logging on flaky tests that
are hard to reproduce.
Bug: 193231132
Test: Manual, using adb command to enable debug logs on userdebug builds
Change-Id: Idf6f7fb35ad02e059582b1f0e7b3b2d006ff0730
diff --git a/services/inputflinger/dispatcher/Android.bp b/services/inputflinger/dispatcher/Android.bp
index ab5c5ef..da4e42f 100644
--- a/services/inputflinger/dispatcher/Android.bp
+++ b/services/inputflinger/dispatcher/Android.bp
@@ -34,6 +34,7 @@
srcs: [
"AnrTracker.cpp",
"Connection.cpp",
+ "DebugConfig.cpp",
"DragState.cpp",
"Entry.cpp",
"FocusResolver.cpp",
diff --git a/services/inputflinger/dispatcher/DebugConfig.cpp b/services/inputflinger/dispatcher/DebugConfig.cpp
new file mode 100644
index 0000000..764194d
--- /dev/null
+++ b/services/inputflinger/dispatcher/DebugConfig.cpp
@@ -0,0 +1,40 @@
+/*
+ * Copyright (C) 2023 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include "DebugConfig.h"
+
+#include <android-base/properties.h>
+
+namespace android::inputdispatcher {
+
+const bool IS_DEBUGGABLE_BUILD =
+#if defined(__ANDROID__)
+ android::base::GetBoolProperty("ro.debuggable", false);
+#else
+ true;
+#endif
+
+bool debugInboundEventDetails() {
+ if (!IS_DEBUGGABLE_BUILD) {
+ static const bool DEBUG_INBOUND_EVENT_DETAILS =
+ __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "InboundEvent",
+ ANDROID_LOG_INFO);
+ return DEBUG_INBOUND_EVENT_DETAILS;
+ }
+ return __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "InboundEvent", ANDROID_LOG_INFO);
+}
+
+} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/DebugConfig.h b/services/inputflinger/dispatcher/DebugConfig.h
index d2ad407..0e260a7 100644
--- a/services/inputflinger/dispatcher/DebugConfig.h
+++ b/services/inputflinger/dispatcher/DebugConfig.h
@@ -22,12 +22,20 @@
#include <log/log_event_list.h>
namespace android::inputdispatcher {
+
+/**
+ * Signals whether this is a debuggable Android build.
+ * This is populated by reading the value of the "ro.debuggable" property.
+ */
+extern const bool IS_DEBUGGABLE_BUILD;
+
/**
* Log detailed debug messages about each inbound event notification to the dispatcher.
- * Enable this via "adb shell setprop log.tag.InputDispatcherInboundEvent DEBUG" (requires restart)
+ * Enable this via "adb shell setprop log.tag.InputDispatcherInboundEvent DEBUG".
+ * This requires a restart on non-debuggable (e.g. user) builds, but should take effect immediately
+ * on debuggable builds (e.g. userdebug).
*/
-const bool DEBUG_INBOUND_EVENT_DETAILS =
- __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "InboundEvent", ANDROID_LOG_INFO);
+bool debugInboundEventDetails();
/**
* Log detailed debug messages about each outbound event processed by the dispatcher.
@@ -90,4 +98,5 @@
*/
const bool DEBUG_HOVER =
__android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG "Hover", ANDROID_LOG_INFO);
+
} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/Entry.cpp b/services/inputflinger/dispatcher/Entry.cpp
index 621543a..b625a1b 100644
--- a/services/inputflinger/dispatcher/Entry.cpp
+++ b/services/inputflinger/dispatcher/Entry.cpp
@@ -14,11 +14,13 @@
* limitations under the License.
*/
+#define LOG_TAG "InputDispatcher"
+
#include "Entry.h"
#include "Connection.h"
+#include "DebugConfig.h"
-#include <android-base/properties.h>
#include <android-base/stringprintf.h>
#include <cutils/atomic.h>
#include <inttypes.h>
@@ -27,13 +29,6 @@
namespace android::inputdispatcher {
-static const bool DEBUGGABLE =
-#if defined(__ANDROID__)
- android::base::GetBoolProperty("ro.debuggable", false);
-#else
- true;
-#endif
-
VerifiedKeyEvent verifiedKeyEventFromKeyEntry(const KeyEntry& entry) {
return {{VerifiedInputEvent::Type::KEY, entry.deviceId, entry.eventTime, entry.source,
entry.displayId},
@@ -178,7 +173,7 @@
KeyEntry::~KeyEntry() {}
std::string KeyEntry::getDescription() const {
- if (!DEBUGGABLE) {
+ if (!IS_DEBUGGABLE_BUILD) {
return "KeyEvent";
}
return StringPrintf("KeyEvent(deviceId=%d, eventTime=%" PRIu64 ", source=%s, displayId=%" PRId32
@@ -248,7 +243,7 @@
MotionEntry::~MotionEntry() {}
std::string MotionEntry::getDescription() const {
- if (!DEBUGGABLE) {
+ if (!IS_DEBUGGABLE_BUILD) {
return "MotionEvent";
}
std::string msg;
@@ -298,7 +293,7 @@
deviceId, inputEventSourceToString(source).c_str(),
ftl::enum_string(sensorType).c_str(), accuracy, hwTimestamp);
- if (DEBUGGABLE) {
+ if (IS_DEBUGGABLE_BUILD) {
for (size_t i = 0; i < values.size(); i++) {
if (i > 0) {
msg += ", ";
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index c9f7512..ab6a116 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -1207,7 +1207,7 @@
const char* reason;
switch (dropReason) {
case DropReason::POLICY:
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("Dropped event because policy consumed it.");
}
reason = "inbound event was dropped because the policy consumed it";
@@ -1596,7 +1596,7 @@
} else if (entry->action == AKEY_EVENT_ACTION_UP && mKeyRepeatState.lastKeyEntry &&
mKeyRepeatState.lastKeyEntry->deviceId != entry->deviceId) {
// The key on device 'deviceId' is still down, do not stop key repeat
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("deviceId=%d got KEY_UP as stale", entry->deviceId);
}
} else if (!entry->syntheticRepeat) {
@@ -4016,7 +4016,7 @@
}
void InputDispatcher::notifyConfigurationChanged(const NotifyConfigurationChangedArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyConfigurationChanged - eventTime=%" PRId64, args->eventTime);
}
@@ -4072,7 +4072,7 @@
}
void InputDispatcher::notifyKey(const NotifyKeyArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyKey - eventTime=%" PRId64 ", deviceId=%d, source=0x%x, displayId=%" PRId32
"policyFlags=0x%x, action=0x%x, "
"flags=0x%x, keyCode=0x%x, scanCode=0x%x, metaState=0x%x, downTime=%" PRId64,
@@ -4150,7 +4150,7 @@
}
void InputDispatcher::notifyMotion(const NotifyMotionArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyMotion - id=%" PRIx32 " eventTime=%" PRId64 ", deviceId=%d, source=0x%x, "
"displayId=%" PRId32 ", policyFlags=0x%x, "
"action=%s, actionButton=0x%x, flags=0x%x, metaState=0x%x, buttonState=0x%x, "
@@ -4261,7 +4261,7 @@
}
void InputDispatcher::notifySensor(const NotifySensorArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifySensor - id=%" PRIx32 " eventTime=%" PRId64 ", deviceId=%d, source=0x%x, "
" sensorType=%s",
args->id, args->eventTime, args->deviceId, args->source,
@@ -4289,7 +4289,7 @@
}
void InputDispatcher::notifyVibratorState(const NotifyVibratorStateArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyVibratorState - eventTime=%" PRId64 ", device=%d, isOn=%d", args->eventTime,
args->deviceId, args->isOn);
}
@@ -4301,7 +4301,7 @@
}
void InputDispatcher::notifySwitch(const NotifySwitchArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifySwitch - eventTime=%" PRId64 ", policyFlags=0x%x, switchValues=0x%08x, "
"switchMask=0x%08x",
args->eventTime, args->policyFlags, args->switchValues, args->switchMask);
@@ -4313,7 +4313,7 @@
}
void InputDispatcher::notifyDeviceReset(const NotifyDeviceResetArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyDeviceReset - eventTime=%" PRId64 ", deviceId=%d", args->eventTime,
args->deviceId);
}
@@ -4333,7 +4333,7 @@
}
void InputDispatcher::notifyPointerCaptureChanged(const NotifyPointerCaptureChangedArgs* args) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("notifyPointerCaptureChanged - eventTime=%" PRId64 ", enabled=%s", args->eventTime,
args->request.enable ? "true" : "false");
}
@@ -4356,7 +4356,7 @@
InputEventInjectionSync syncMode,
std::chrono::milliseconds timeout,
uint32_t policyFlags) {
- if (DEBUG_INBOUND_EVENT_DETAILS) {
+ if (debugInboundEventDetails()) {
ALOGD("injectInputEvent - eventType=%d, targetUid=%s, syncMode=%d, timeout=%lld, "
"policyFlags=0x%08x",
event->getType(), targetUid ? std::to_string(*targetUid).c_str() : "none", syncMode,