diff --git a/libs/input/KeyCharacterMap.cpp b/libs/input/KeyCharacterMap.cpp index e189d20e2..1694ab601 100644 --- a/libs/input/KeyCharacterMap.cpp +++ b/libs/input/KeyCharacterMap.cpp @@ -34,14 +34,13 @@ #include // Enables debug output for the parser. -#define DEBUG_PARSER 0 +#define DEBUG_PARSER 1 // Enables debug output for parser performance. -#define DEBUG_PARSER_PERFORMANCE 0 +#define DEBUG_PARSER_PERFORMANCE 1 // Enables debug output for mapping. -#define DEBUG_MAPPING 0 - +#define DEBUG_MAPPING 1 namespace android { diff --git a/libs/input/KeyLayoutMap.cpp b/libs/input/KeyLayoutMap.cpp index efca68d17..a84d57c56 100644 --- a/libs/input/KeyLayoutMap.cpp +++ b/libs/input/KeyLayoutMap.cpp @@ -28,13 +28,13 @@ #include // Enables debug output for the parser. -#define DEBUG_PARSER 0 +#define DEBUG_PARSER 1 // Enables debug output for parser performance. -#define DEBUG_PARSER_PERFORMANCE 0 +#define DEBUG_PARSER_PERFORMANCE 1 // Enables debug output for mapping. -#define DEBUG_MAPPING 0 +#define DEBUG_MAPPING 1 namespace android { diff --git a/services/inputflinger/InputDispatcher.cpp b/services/inputflinger/InputDispatcher.cpp index aea026823..73ee35d17 100644 --- a/services/inputflinger/InputDispatcher.cpp +++ b/services/inputflinger/InputDispatcher.cpp @@ -20,28 +20,28 @@ #define LOG_NDEBUG 0 // Log detailed debug messages about each inbound event notification to the dispatcher. -#define DEBUG_INBOUND_EVENT_DETAILS 0 +#define DEBUG_INBOUND_EVENT_DETAILS 1 // Log detailed debug messages about each outbound event processed by the dispatcher. -#define DEBUG_OUTBOUND_EVENT_DETAILS 0 +#define DEBUG_OUTBOUND_EVENT_DETAILS 1 // Log debug messages about the dispatch cycle. -#define DEBUG_DISPATCH_CYCLE 0 +#define DEBUG_DISPATCH_CYCLE 1 // Log debug messages about registrations. -#define DEBUG_REGISTRATION 0 +#define DEBUG_REGISTRATION 1 // Log debug messages about input event injection. -#define DEBUG_INJECTION 0 +#define DEBUG_INJECTION 1 // Log debug messages about input focus tracking. -#define DEBUG_FOCUS 0 +#define DEBUG_FOCUS 1 // Log debug messages about the app switch latency optimization. -#define DEBUG_APP_SWITCH 0 +#define DEBUG_APP_SWITCH 1 // Log debug messages about hover events. -#define DEBUG_HOVER 0 +#define DEBUG_HOVER 1 #include "InputDispatcher.h" @@ -65,6 +65,8 @@ #define INDENT3 " " #define INDENT4 " " +#define BLOGI(...) ALOG(LOG_INFO, "BFXBTF-484", __VA_ARGS__) + using android::base::StringPrintf; namespace android { @@ -290,6 +292,7 @@ void InputDispatcher::dispatchOnce() { void InputDispatcher::dispatchOnceInnerLocked(nsecs_t* nextWakeupTime) { nsecs_t currentTime = now(); + ALOGI("===> traceKey A10, mDispatchEnabled=%d, mDispatchFrozen=%d in %s of %s line %d" ,mDispatchEnabled ,mDispatchFrozen ,__func__ ,__FILE__ ,__LINE__); // Reset the key repeat timer whenever normal dispatch is suspended while the // device is in a non-interactive state. This is to ensure that we abort a key // repeat if the device is just coming out of sleep. @@ -302,6 +305,7 @@ void InputDispatcher::dispatchOnceInnerLocked(nsecs_t* nextWakeupTime) { #if DEBUG_FOCUS ALOGD("Dispatch frozen. Waiting some more."); #endif + ALOGI("===> traceKey A9.2 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); return; } @@ -337,6 +341,7 @@ void InputDispatcher::dispatchOnceInnerLocked(nsecs_t* nextWakeupTime) { // Nothing to do if there is no pending event. if (!mPendingEvent) { + ALOGI("===> traceKey A9.1 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); return; } } else { @@ -354,6 +359,7 @@ void InputDispatcher::dispatchOnceInnerLocked(nsecs_t* nextWakeupTime) { resetANRTimeoutsLocked(); } + ALOGI("===> traceKey A9 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); // Now we have an event to dispatch. // All events are eventually dequeued and processed this way, even if we intend to drop them. ALOG_ASSERT(mPendingEvent != nullptr); @@ -403,6 +409,7 @@ void InputDispatcher::dispatchOnceInnerLocked(nsecs_t* nextWakeupTime) { if (dropReason == DROP_REASON_NOT_DROPPED && mNextUnblockedEvent) { dropReason = DROP_REASON_BLOCKED; } + ALOGI("===> traceKey A8, keycode=%d, in %s of %s line %d" ,typedEntry->keyCode ,__func__ ,__FILE__ ,__LINE__); done = dispatchKeyLocked(currentTime, typedEntry, &dropReason, nextWakeupTime); break; } @@ -795,6 +802,7 @@ bool InputDispatcher::dispatchDeviceResetLocked( bool InputDispatcher::dispatchKeyLocked(nsecs_t currentTime, KeyEntry* entry, DropReason* dropReason, nsecs_t* nextWakeupTime) { + ALOGI("===> traceKey A7.2, keycode=%d, interceptKeyResult=%d, in %s of %s line %d" ,entry->keyCode ,entry->interceptKeyResult ,__func__ ,__FILE__ ,__LINE__); // Preprocessing. if (! entry->dispatchInProgress) { if (entry->repeatCount == 0 @@ -838,15 +846,18 @@ bool InputDispatcher::dispatchKeyLocked(nsecs_t currentTime, KeyEntry* entry, if (entry->interceptKeyWakeupTime < *nextWakeupTime) { *nextWakeupTime = entry->interceptKeyWakeupTime; } + ALOGI("===> traceKey A7.1, keycode=%d, interceptKeyResult=%d, in %s of %s line %d" ,entry->keyCode ,entry->interceptKeyResult ,__func__ ,__FILE__ ,__LINE__); return false; // wait until next wakeup } entry->interceptKeyResult = KeyEntry::INTERCEPT_KEY_RESULT_UNKNOWN; entry->interceptKeyWakeupTime = 0; } + ALOGI("===> traceKey A7, keycode=%d, interceptKeyResult=%d, in %s of %s line %d" ,entry->keyCode ,entry->interceptKeyResult ,__func__ ,__FILE__ ,__LINE__); // Give the policy a chance to intercept the key. if (entry->interceptKeyResult == KeyEntry::INTERCEPT_KEY_RESULT_UNKNOWN) { if (entry->policyFlags & POLICY_FLAG_PASS_TO_USER) { + ALOGI("===> traceKey A6, keycode=%d, interceptKeyResult=%d, in %s of %s line %d" ,entry->keyCode ,entry->interceptKeyResult ,__func__ ,__FILE__ ,__LINE__); CommandEntry* commandEntry = postCommandLocked( & InputDispatcher::doInterceptKeyBeforeDispatchingLockedInterruptible); sp focusedWindowHandle = @@ -866,12 +877,14 @@ bool InputDispatcher::dispatchKeyLocked(nsecs_t currentTime, KeyEntry* entry, *dropReason = DROP_REASON_POLICY; } } + //ALOGI("===> traceKey A5.5, keycode=%d, interceptKeyResult=%d in %s of %s line %d", entry->keyCode, entry->interceptKeyResult, __func__, __FILE__, __LINE__); // Clean up if dropping the event. if (*dropReason != DROP_REASON_NOT_DROPPED) { setInjectionResult(entry, *dropReason == DROP_REASON_POLICY ? INPUT_EVENT_INJECTION_SUCCEEDED : INPUT_EVENT_INJECTION_FAILED); mReporter->reportDroppedKey(entry->sequenceNum); + ALOGI("===> traceKey A5.4, keycode=%d, interceptKeyResult=%d in %s of %s line %d", entry->keyCode, entry->interceptKeyResult, __func__, __FILE__, __LINE__); return true; } @@ -880,17 +893,20 @@ bool InputDispatcher::dispatchKeyLocked(nsecs_t currentTime, KeyEntry* entry, int32_t injectionResult = findFocusedWindowTargetsLocked(currentTime, entry, inputTargets, nextWakeupTime); if (injectionResult == INPUT_EVENT_INJECTION_PENDING) { + ALOGI("===> traceKey A5.3, keycode=%d, interceptKeyResult=%d in %s of %s line %d", entry->keyCode, entry->interceptKeyResult, __func__, __FILE__, __LINE__); return false; } setInjectionResult(entry, injectionResult); if (injectionResult != INPUT_EVENT_INJECTION_SUCCEEDED) { + ALOGI("===> traceKey A5.2, keycode=%d, interceptKeyResult=%d in %s of %s line %d", entry->keyCode, entry->interceptKeyResult, __func__, __FILE__, __LINE__); return true; } // Add monitor channels from event's or focused display. addGlobalMonitoringTargetsLocked(inputTargets, getTargetDisplayId(entry)); + //ALOGI("===> traceKey A5.1, keycode=%d, interceptKeyResult=%d in %s of %s line %d", entry->keyCode, entry->interceptKeyResult, __func__, __FILE__, __LINE__); // Dispatch the key. dispatchEventLocked(currentTime, entry, inputTargets); return true; @@ -4165,6 +4181,7 @@ void InputDispatcher::doInterceptKeyBeforeDispatchingLockedInterruptible( android::base::Timer t; sp token = commandEntry->inputChannel != nullptr ? commandEntry->inputChannel->getToken() : nullptr; + ALOGI("===> traceKey A5, keycode=%d in %s of %s line %d", event.getKeyCode(), __func__, __FILE__, __LINE__); nsecs_t delay = mPolicy->interceptKeyBeforeDispatching(token, &event, entry->policyFlags); if (t.duration() > SLOW_INTERCEPTION_THRESHOLD) { diff --git a/services/inputflinger/InputReader.cpp b/services/inputflinger/InputReader.cpp index b3734e5c6..336560363 100644 --- a/services/inputflinger/InputReader.cpp +++ b/services/inputflinger/InputReader.cpp @@ -19,13 +19,13 @@ //#define LOG_NDEBUG 0 // Log debug messages for each raw event received from the EventHub. -#define DEBUG_RAW_EVENTS 0 +#define DEBUG_RAW_EVENTS 1 // Log debug messages about touch screen filtering hacks. #define DEBUG_HACKS 0 // Log debug messages about virtual key processing. -#define DEBUG_VIRTUAL_KEYS 0 +#define DEBUG_VIRTUAL_KEYS 1 // Log debug messages about pointers. #define DEBUG_POINTERS 0 @@ -65,6 +65,8 @@ #define INDENT4 " " #define INDENT5 " " +#define BLOGI(...) ALOG(LOG_INFO, "BFXBTF-484", __VA_ARGS__) + using android::base::StringPrintf; namespace android { @@ -312,6 +314,7 @@ void InputReader::loopOnce() { mReaderIsAliveCondition.broadcast(); if (count) { + ALOGI("===> traceKey C3 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); processEventsLocked(mEventBuffer, count); } @@ -344,6 +347,7 @@ void InputReader::loopOnce() { // resulting in a deadlock. This situation is actually quite plausible because the // listener is actually the input dispatcher, which calls into the window manager, // which occasionally calls into the input reader. + ALOGI("===> traceKey C0 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); mQueuedListener->flush(); } @@ -363,6 +367,7 @@ void InputReader::processEventsLocked(const RawEvent* rawEvents, size_t count) { #if DEBUG_RAW_EVENTS ALOGD("BatchSize: %zu Count: %zu", batchSize, count); #endif + ALOGI("===> traceKey C2 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); processEventsForDeviceLocked(deviceId, rawEvent, batchSize); } else { switch (rawEvent->type) { @@ -524,15 +529,18 @@ void InputReader::processEventsForDeviceLocked(int32_t deviceId, ssize_t deviceIndex = mDevices.indexOfKey(deviceId); if (deviceIndex < 0) { ALOGW("Discarding event for unknown deviceId %d.", deviceId); + BLOGI("===> traceKey C1.2 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); return; } InputDevice* device = mDevices.valueAt(deviceIndex); if (device->isIgnored()) { //ALOGD("Discarding event for ignored deviceId %d.", deviceId); + BLOGI("===> traceKey C1.1 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); return; } + ALOGI("===> traceKey C1 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); device->process(rawEvents, count); } @@ -1159,6 +1167,7 @@ void InputDevice::process(const RawEvent* rawEvents, size_t count) { reset(rawEvent->when); } else { for (InputMapper* mapper : mMappers) { + ALOGI("===> traceKey C0.2 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); mapper->process(rawEvent); } } @@ -2302,6 +2311,7 @@ void KeyboardInputMapper::process(const RawEvent* rawEvent) { mCurrentHidUsage = 0; if (isKeyboardOrGamepadKey(scanCode)) { + ALOGI("===> traceKey C0.1 in %s of %s line %d" ,__func__ ,__FILE__ ,__LINE__); processKey(rawEvent->when, rawEvent->value != 0, scanCode, usageCode); } break;