From a35dc99840443d40cec178b0b155b9c6c62bf506 Mon Sep 17 00:00:00 2001 From: Harry Cutts Date: Tue, 4 Mar 2025 13:16:34 +0000 Subject: TouchInputMapper: Add logs for b/396796958 In this bug, we're seeing test flakes where touches don't get through to a test activity, and the raw event logs show "syncTouch: pointerCount 0 -> 1" multiple times in a row. To get us some better debugging data, dump the whole InputReader state as well as the last and next RawStates when this happens. Bug: 396796958 Test: enable raw event logs: $ adb shell 'stop && setprop log.tag.InputReaderRawEvents DEBUG && start' then touch the screen and check the dump appears in the logs. Test: touch screen and check output of $ adb shell dumpsys input Test: $ atest --host inputflinger_tests Test: $ m checkinput Flag: EXEMPT log only update Change-Id: I8f1c9ec772971f3e3deefbae94bcae678b1083f4 --- services/inputflinger/reader/InputReader.cpp | 10 ++++ services/inputflinger/reader/include/InputReader.h | 4 ++ .../reader/include/InputReaderContext.h | 3 + .../reader/mapper/TouchInputMapper.cpp | 68 +++++++++++++++++----- .../inputflinger/reader/mapper/TouchInputMapper.h | 2 + 5 files changed, 73 insertions(+), 14 deletions(-) (limited to 'services/inputflinger/reader') diff --git a/services/inputflinger/reader/InputReader.cpp b/services/inputflinger/reader/InputReader.cpp index 845cab05d3..58df692b3e 100644 --- a/services/inputflinger/reader/InputReader.cpp +++ b/services/inputflinger/reader/InputReader.cpp @@ -32,6 +32,7 @@ #include #include #include +#include #include "InputDevice.h" #include "include/gestures.h" @@ -945,7 +946,10 @@ bool InputReader::setKernelWakeEnabled(int32_t deviceId, bool enabled) { void InputReader::dump(std::string& dump) { std::scoped_lock _l(mLock); + dumpLocked(dump); +} +void InputReader::dumpLocked(std::string& dump) { mEventHub->dump(dump); dump += "\n"; @@ -1032,6 +1036,12 @@ void InputReader::monitor() { InputReader::ContextImpl::ContextImpl(InputReader* reader) : mReader(reader), mIdGenerator(IdGenerator::Source::INPUT_READER) {} +std::string InputReader::ContextImpl::dump() { + std::string dump; + mReader->dumpLocked(dump); + return dump; +} + void InputReader::ContextImpl::updateGlobalMetaState() { // lock is already held by the input loop mReader->updateGlobalMetaStateLocked(); diff --git a/services/inputflinger/reader/include/InputReader.h b/services/inputflinger/reader/include/InputReader.h index 0d6e1020c1..6a259373df 100644 --- a/services/inputflinger/reader/include/InputReader.h +++ b/services/inputflinger/reader/include/InputReader.h @@ -21,6 +21,7 @@ #include #include +#include #include #include @@ -142,6 +143,7 @@ protected: public: explicit ContextImpl(InputReader* reader); + std::string dump() REQUIRES(mReader->mLock) override; // lock is already held by the input loop void updateGlobalMetaState() NO_THREAD_SAFETY_ANALYSIS override; int32_t getGlobalMetaState() NO_THREAD_SAFETY_ANALYSIS override; @@ -216,6 +218,8 @@ private: // The input device that produced a new gesture most recently. DeviceId mLastUsedDeviceId GUARDED_BY(mLock){ReservedInputDeviceId::INVALID_INPUT_DEVICE_ID}; + void dumpLocked(std::string& dump) REQUIRES(mLock); + // low-level input event decoding and device management [[nodiscard]] std::list processEventsLocked(const RawEvent* rawEvents, size_t count) REQUIRES(mLock); diff --git a/services/inputflinger/reader/include/InputReaderContext.h b/services/inputflinger/reader/include/InputReaderContext.h index 20ed74fef7..f38fd7b8ac 100644 --- a/services/inputflinger/reader/include/InputReaderContext.h +++ b/services/inputflinger/reader/include/InputReaderContext.h @@ -20,6 +20,7 @@ #include #include "NotifyArgs.h" +#include #include namespace android { @@ -39,6 +40,8 @@ public: InputReaderContext() {} virtual ~InputReaderContext() {} + virtual std::string dump() = 0; + virtual void updateGlobalMetaState() = 0; virtual int32_t getGlobalMetaState() = 0; diff --git a/services/inputflinger/reader/mapper/TouchInputMapper.cpp b/services/inputflinger/reader/mapper/TouchInputMapper.cpp index 8deff6b3aa..4d36db8ff7 100644 --- a/services/inputflinger/reader/mapper/TouchInputMapper.cpp +++ b/services/inputflinger/reader/mapper/TouchInputMapper.cpp @@ -24,6 +24,8 @@ #include #include #include +#include +#include #include #include @@ -138,6 +140,40 @@ void RawPointerData::getCentroidOfTouchingPointers(float* outX, float* outY) con *outY = y; } +std::ostream& operator<<(std::ostream& out, const RawPointerData::Pointer& p) { + out << "id=" << p.id << ", x=" << p.x << ", y=" << p.y << ", pressure=" << p.pressure + << ", touchMajor=" << p.touchMajor << ", touchMinor=" << p.touchMinor + << ", toolMajor=" << p.toolMajor << ", toolMinor=" << p.toolMinor + << ", orientation=" << p.orientation << ", tiltX=" << p.tiltX << ", tiltY=" << p.tiltY + << ", distance=" << p.distance << ", toolType=" << ftl::enum_string(p.toolType) + << ", isHovering=" << p.isHovering; + return out; +} + +std::ostream& operator<<(std::ostream& out, const RawPointerData& data) { + out << data.pointerCount << " pointers:\n"; + for (uint32_t i = 0; i < data.pointerCount; i++) { + out << INDENT << "[" << i << "]: " << data.pointers[i] << std::endl; + } + out << "ID bits: hovering = 0x" << std::hex << std::setfill('0') << std::setw(8) + << data.hoveringIdBits.value << ", touching = 0x" << std::setfill('0') << std::setw(8) + << data.touchingIdBits.value << ", canceled = 0x" << std::setfill('0') << std::setw(8) + << data.canceledIdBits.value << std::dec; + return out; +} + +// --- TouchInputMapper::RawState --- + +std::ostream& operator<<(std::ostream& out, const TouchInputMapper::RawState& state) { + out << "When: " << state.when << std::endl; + out << "Read time: " << state.readTime << std::endl; + out << "Button state: 0x" << std::setfill('0') << std::setw(8) << std::hex << state.buttonState + << std::dec << std::endl; + out << "Raw pointer data:" << std::endl; + out << addLinePrefix(streamableToString(state.rawPointerData), INDENT); + return out; +} + // --- TouchInputMapper --- TouchInputMapper::TouchInputMapper(InputDeviceContext& deviceContext, @@ -232,20 +268,8 @@ void TouchInputMapper::dump(std::string& dump) { dump += StringPrintf(INDENT4 "TiltYScale: %0.3f\n", mTiltYScale); dump += StringPrintf(INDENT3 "Last Raw Button State: 0x%08x\n", mLastRawState.buttonState); - dump += StringPrintf(INDENT3 "Last Raw Touch: pointerCount=%d\n", - mLastRawState.rawPointerData.pointerCount); - for (uint32_t i = 0; i < mLastRawState.rawPointerData.pointerCount; i++) { - const RawPointerData::Pointer& pointer = mLastRawState.rawPointerData.pointers[i]; - dump += StringPrintf(INDENT4 "[%d]: id=%d, x=%d, y=%d, pressure=%d, " - "touchMajor=%d, touchMinor=%d, toolMajor=%d, toolMinor=%d, " - "orientation=%d, tiltX=%d, tiltY=%d, distance=%d, " - "toolType=%s, isHovering=%s\n", - i, pointer.id, pointer.x, pointer.y, pointer.pressure, - pointer.touchMajor, pointer.touchMinor, pointer.toolMajor, - pointer.toolMinor, pointer.orientation, pointer.tiltX, pointer.tiltY, - pointer.distance, ftl::enum_string(pointer.toolType).c_str(), - toString(pointer.isHovering)); - } + dump += INDENT3 "Last Raw Touch:\n"; + dump += addLinePrefix(streamableToString(mLastRawState), INDENT4) + "\n"; dump += StringPrintf(INDENT3 "Last Cooked Button State: 0x%08x\n", mLastCookedState.buttonState); @@ -1476,6 +1500,22 @@ std::list TouchInputMapper::sync(nsecs_t when, nsecs_t readTime) { last.rawPointerData.touchingIdBits.value, next.rawPointerData.touchingIdBits.value, last.rawPointerData.hoveringIdBits.value, next.rawPointerData.hoveringIdBits.value, next.rawPointerData.canceledIdBits.value); + if (debugRawEvents() && last.rawPointerData.pointerCount == 0 && + next.rawPointerData.pointerCount == 1) { + // Dump a bunch of info to try to debug b/396796958. + // TODO(b/396796958): remove this debug dump. + ALOGD("pointerCount went from 0 to 1. last:\n%s", + addLinePrefix(streamableToString(last), INDENT).c_str()); + ALOGD("next:\n%s", addLinePrefix(streamableToString(next), INDENT).c_str()); + ALOGD("InputReader dump:"); + // The dump is too long to simply add as a format parameter in one log message, so we have + // to split it by line and log them individually. + std::istringstream stream(mDeviceContext.getContext()->dump()); + std::string line; + while (std::getline(stream, line, '\n')) { + ALOGD(INDENT "%s", line.c_str()); + } + } if (!next.rawPointerData.touchingIdBits.isEmpty() && !next.rawPointerData.hoveringIdBits.isEmpty() && diff --git a/services/inputflinger/reader/mapper/TouchInputMapper.h b/services/inputflinger/reader/mapper/TouchInputMapper.h index 4ef0be8f8e..45fc6bfa36 100644 --- a/services/inputflinger/reader/mapper/TouchInputMapper.h +++ b/services/inputflinger/reader/mapper/TouchInputMapper.h @@ -348,6 +348,8 @@ protected: inline void clear() { *this = RawState(); } }; + friend std::ostream& operator<<(std::ostream& out, const RawState& state); + struct CookedState { // Cooked pointer sample data. CookedPointerData cookedPointerData{}; -- cgit v1.2.3-59-g8ed1b