diff options
author | 2023-09-26 15:35:12 +0000 | |
---|---|---|
committer | 2023-10-09 17:21:51 +0000 | |
commit | dd9a6cdf69896d93e22718c11b30c29952125a14 (patch) | |
tree | 951447d0ec82d23de2c3920d44aad6d70a8ff799 | |
parent | 62d4c246d3c55b5335a9aa26ac9578e2a7f5f6c0 (diff) |
Pass ProductId+VendorId+Source info to LatencyTracker
Currently InputEventLatencySketch captures the aggregated latency over
all devices, and it doesn't capture per-device latency.
In order to capture latency metrics per device, we track the timeline
for latency information for each Product Id, Vendor Id and Source
individually.
Bug: 270049345
Test: atest inputflinger_tests:LatencyTrackerTest
Change-Id: Ic3265e25ff95266e8cfe8542d4f4afb7b6ac16b1
9 files changed, 168 insertions, 27 deletions
diff --git a/services/inputflinger/InputDeviceMetricsSource.h b/services/inputflinger/InputDeviceMetricsSource.h index 3ac91c812a..a6be8f42cc 100644 --- a/services/inputflinger/InputDeviceMetricsSource.h +++ b/services/inputflinger/InputDeviceMetricsSource.h @@ -47,6 +47,8 @@ enum class InputDeviceUsageSource : int32_t { ftl_first = UNKNOWN, ftl_last = TRACKBALL, + // Used by latency fuzzer + kMaxValue = ftl_last }; /** Returns the InputDeviceUsageSource that corresponds to the key event. */ diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp index 6226a19897..16ce1e4f13 100644 --- a/services/inputflinger/dispatcher/InputDispatcher.cpp +++ b/services/inputflinger/dispatcher/InputDispatcher.cpp @@ -46,6 +46,8 @@ #include <queue> #include <sstream> +#include "../InputDeviceMetricsSource.h" + #include "Connection.h" #include "DebugConfig.h" #include "InputDispatcher.h" @@ -4183,6 +4185,11 @@ std::unique_ptr<MotionEntry> InputDispatcher::splitMotionEvent( return splitMotionEntry; } +void InputDispatcher::notifyInputDevicesChanged(const NotifyInputDevicesChangedArgs& args) { + std::scoped_lock _l(mLock); + mLatencyTracker.setInputDevices(args.inputDeviceInfos); +} + void InputDispatcher::notifyConfigurationChanged(const NotifyConfigurationChangedArgs& args) { if (debugInboundEventDetails()) { ALOGD("notifyConfigurationChanged - eventTime=%" PRId64, args.eventTime); @@ -4395,7 +4402,9 @@ void InputDispatcher::notifyMotion(const NotifyMotionArgs& args) { IdGenerator::getSource(args.id) == IdGenerator::Source::INPUT_READER && !mInputFilterEnabled) { const bool isDown = args.action == AMOTION_EVENT_ACTION_DOWN; - mLatencyTracker.trackListener(args.id, isDown, args.eventTime, args.readTime); + std::set<InputDeviceUsageSource> sources = getUsageSourcesForMotionArgs(args); + mLatencyTracker.trackListener(args.id, isDown, args.eventTime, args.readTime, + args.deviceId, sources); } needWake = enqueueInboundEventLocked(std::move(newEntry)); diff --git a/services/inputflinger/dispatcher/InputDispatcher.h b/services/inputflinger/dispatcher/InputDispatcher.h index 62e2d583d6..ee5a797a87 100644 --- a/services/inputflinger/dispatcher/InputDispatcher.h +++ b/services/inputflinger/dispatcher/InputDispatcher.h @@ -92,7 +92,7 @@ public: status_t start() override; status_t stop() override; - void notifyInputDevicesChanged(const NotifyInputDevicesChangedArgs& args) override{}; + void notifyInputDevicesChanged(const NotifyInputDevicesChangedArgs& args) override; void notifyConfigurationChanged(const NotifyConfigurationChangedArgs& args) override; void notifyKey(const NotifyKeyArgs& args) override; void notifyMotion(const NotifyMotionArgs& args) override; diff --git a/services/inputflinger/dispatcher/InputEventTimeline.cpp b/services/inputflinger/dispatcher/InputEventTimeline.cpp index 3edb6381d4..a7c6d162d8 100644 --- a/services/inputflinger/dispatcher/InputEventTimeline.cpp +++ b/services/inputflinger/dispatcher/InputEventTimeline.cpp @@ -16,6 +16,8 @@ #include "InputEventTimeline.h" +#include "../InputDeviceMetricsSource.h" + namespace android::inputdispatcher { ConnectionTimeline::ConnectionTimeline(nsecs_t deliveryTime, nsecs_t consumeTime, @@ -64,8 +66,15 @@ bool ConnectionTimeline::operator!=(const ConnectionTimeline& rhs) const { return !operator==(rhs); } -InputEventTimeline::InputEventTimeline(bool isDown, nsecs_t eventTime, nsecs_t readTime) - : isDown(isDown), eventTime(eventTime), readTime(readTime) {} +InputEventTimeline::InputEventTimeline(bool isDown, nsecs_t eventTime, nsecs_t readTime, + uint16_t vendorId, uint16_t productId, + std::set<InputDeviceUsageSource> sources) + : isDown(isDown), + eventTime(eventTime), + readTime(readTime), + vendorId(vendorId), + productId(productId), + sources(sources) {} bool InputEventTimeline::operator==(const InputEventTimeline& rhs) const { if (connectionTimelines.size() != rhs.connectionTimelines.size()) { @@ -80,7 +89,8 @@ bool InputEventTimeline::operator==(const InputEventTimeline& rhs) const { return false; } } - return isDown == rhs.isDown && eventTime == rhs.eventTime && readTime == rhs.readTime; + return isDown == rhs.isDown && eventTime == rhs.eventTime && readTime == rhs.readTime && + vendorId == rhs.vendorId && productId == rhs.productId && sources == rhs.sources; } } // namespace android::inputdispatcher diff --git a/services/inputflinger/dispatcher/InputEventTimeline.h b/services/inputflinger/dispatcher/InputEventTimeline.h index daf375d918..e9deb2d3cf 100644 --- a/services/inputflinger/dispatcher/InputEventTimeline.h +++ b/services/inputflinger/dispatcher/InputEventTimeline.h @@ -16,6 +16,8 @@ #pragma once +#include "../InputDeviceMetricsSource.h" + #include <binder/IBinder.h> #include <input/Input.h> #include <unordered_map> @@ -73,10 +75,14 @@ private: }; struct InputEventTimeline { - InputEventTimeline(bool isDown, nsecs_t eventTime, nsecs_t readTime); + InputEventTimeline(bool isDown, nsecs_t eventTime, nsecs_t readTime, uint16_t vendorId, + uint16_t productId, std::set<InputDeviceUsageSource> sources); const bool isDown; // True if this is an ACTION_DOWN event const nsecs_t eventTime; const nsecs_t readTime; + const uint16_t vendorId; + const uint16_t productId; + const std::set<InputDeviceUsageSource> sources; struct IBinderHash { std::size_t operator()(const sp<IBinder>& b) const { diff --git a/services/inputflinger/dispatcher/LatencyTracker.cpp b/services/inputflinger/dispatcher/LatencyTracker.cpp index b7c36a8db8..698bd9ff08 100644 --- a/services/inputflinger/dispatcher/LatencyTracker.cpp +++ b/services/inputflinger/dispatcher/LatencyTracker.cpp @@ -16,6 +16,7 @@ #define LOG_TAG "LatencyTracker" #include "LatencyTracker.h" +#include "../InputDeviceMetricsSource.h" #include <inttypes.h> @@ -23,6 +24,7 @@ #include <android-base/stringprintf.h> #include <android/os/IInputConstants.h> #include <input/Input.h> +#include <input/InputDevice.h> #include <log/log.h> using android::base::HwTimeoutMultiplier; @@ -66,7 +68,8 @@ LatencyTracker::LatencyTracker(InputEventTimelineProcessor* processor) } void LatencyTracker::trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime, - nsecs_t readTime) { + nsecs_t readTime, DeviceId deviceId, + const std::set<InputDeviceUsageSource>& sources) { reportAndPruneMatureRecords(eventTime); const auto it = mTimelines.find(inputEventId); if (it != mTimelines.end()) { @@ -78,7 +81,29 @@ void LatencyTracker::trackListener(int32_t inputEventId, bool isDown, nsecs_t ev eraseByValue(mEventTimes, inputEventId); return; } - mTimelines.emplace(inputEventId, InputEventTimeline(isDown, eventTime, readTime)); + + // Create an InputEventTimeline for the device ID. The vendorId and productId + // can be obtained from the InputDeviceIdentifier of the particular device. + const InputDeviceIdentifier* identifier = nullptr; + for (auto& inputDevice : mInputDevices) { + if (deviceId == inputDevice.getId()) { + identifier = &inputDevice.getIdentifier(); + break; + } + } + + // If no matching ids can be found for the device from among the input devices connected, + // the call to trackListener will be dropped. + // Note: there generally isn't expected to be a situation where we can't find an InputDeviceInfo + // but a possibility of it is handled in case of race conditions + if (identifier == nullptr) { + ALOGE("Could not find input device identifier. Dropping call to LatencyTracker."); + return; + } + + mTimelines.emplace(inputEventId, + InputEventTimeline(isDown, eventTime, readTime, identifier->vendor, + identifier->product, sources)); mEventTimes.emplace(eventTime, inputEventId); } @@ -171,4 +196,8 @@ std::string LatencyTracker::dump(const char* prefix) const { StringPrintf("%s mEventTimes.size() = %zu\n", prefix, mEventTimes.size()); } +void LatencyTracker::setInputDevices(const std::vector<InputDeviceInfo>& inputDevices) { + mInputDevices = inputDevices; +} + } // namespace android::inputdispatcher diff --git a/services/inputflinger/dispatcher/LatencyTracker.h b/services/inputflinger/dispatcher/LatencyTracker.h index 4212da876f..890d61d431 100644 --- a/services/inputflinger/dispatcher/LatencyTracker.h +++ b/services/inputflinger/dispatcher/LatencyTracker.h @@ -16,6 +16,8 @@ #pragma once +#include "../InputDeviceMetricsSource.h" + #include <map> #include <unordered_map> @@ -23,6 +25,7 @@ #include <input/Input.h> #include "InputEventTimeline.h" +#include "NotifyArgs.h" namespace android::inputdispatcher { @@ -49,13 +52,15 @@ public: * duplicate events that happen to have the same eventTime and inputEventId. Therefore, we * must drop all duplicate data. */ - void trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime, nsecs_t readTime); + void trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime, nsecs_t readTime, + DeviceId deviceId, const std::set<InputDeviceUsageSource>& sources); void trackFinishedEvent(int32_t inputEventId, const sp<IBinder>& connectionToken, nsecs_t deliveryTime, nsecs_t consumeTime, nsecs_t finishTime); void trackGraphicsLatency(int32_t inputEventId, const sp<IBinder>& connectionToken, std::array<nsecs_t, GraphicsTimeline::SIZE> timeline); std::string dump(const char* prefix) const; + void setInputDevices(const std::vector<InputDeviceInfo>& inputDevices); private: /** @@ -76,6 +81,7 @@ private: std::multimap<nsecs_t /*eventTime*/, int32_t /*inputEventId*/> mEventTimes; InputEventTimelineProcessor* mTimelineProcessor; + std::vector<InputDeviceInfo> mInputDevices; void reportAndPruneMatureRecords(nsecs_t newEventTime); }; diff --git a/services/inputflinger/tests/LatencyTracker_test.cpp b/services/inputflinger/tests/LatencyTracker_test.cpp index fa149dba05..6606de896b 100644 --- a/services/inputflinger/tests/LatencyTracker_test.cpp +++ b/services/inputflinger/tests/LatencyTracker_test.cpp @@ -15,11 +15,14 @@ */ #include "../dispatcher/LatencyTracker.h" +#include "../InputDeviceMetricsSource.h" #include <android-base/properties.h> #include <binder/Binder.h> #include <gtest/gtest.h> +#include <gui/constants.h> #include <inttypes.h> +#include <linux/input.h> #include <log/log.h> #define TAG "LatencyTracker_test" @@ -30,6 +33,29 @@ using android::inputdispatcher::LatencyTracker; namespace android::inputdispatcher { +namespace { + +constexpr DeviceId DEVICE_ID = 100; + +static InputDeviceInfo generateTestDeviceInfo(uint16_t vendorId, uint16_t productId, + DeviceId deviceId) { + InputDeviceIdentifier identifier; + identifier.vendor = vendorId; + identifier.product = productId; + auto info = InputDeviceInfo(); + info.initialize(deviceId, /*generation=*/1, /*controllerNumber=*/1, identifier, "Test Device", + /*isExternal=*/false, /*hasMic=*/false, ADISPLAY_ID_NONE); + return info; +} + +void setDefaultInputDeviceInfo(LatencyTracker& tracker) { + InputDeviceInfo deviceInfo = generateTestDeviceInfo( + /*vendorId=*/0, /*productId=*/0, DEVICE_ID); + tracker.setInputDevices({deviceInfo}); +} + +} // namespace + const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds( android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS * HwTimeoutMultiplier()); @@ -38,7 +64,10 @@ InputEventTimeline getTestTimeline() { InputEventTimeline t( /*isDown=*/true, /*eventTime=*/2, - /*readTime=*/3); + /*readTime=*/3, + /*vendorId=*/0, + /*productId=*/0, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}); ConnectionTimeline expectedCT(/*deliveryTime=*/6, /*consumeTime=*/7, /*finishTime=*/8); std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline; graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 9; @@ -60,6 +89,7 @@ protected: connection2 = sp<BBinder>::make(); mTracker = std::make_unique<LatencyTracker>(this); + setDefaultInputDeviceInfo(*mTracker); } void TearDown() override {} @@ -88,7 +118,8 @@ void LatencyTrackerTest::triggerEventReporting(nsecs_t lastEventTime) { const nsecs_t triggerEventTime = lastEventTime + std::chrono::nanoseconds(ANR_TIMEOUT).count() + 1; mTracker->trackListener(/*inputEventId=*/1, /*isDown=*/true, triggerEventTime, - /*readTime=*/3); + /*readTime=*/3, DEVICE_ID, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}); } void LatencyTrackerTest::assertReceivedTimeline(const InputEventTimeline& timeline) { @@ -138,9 +169,11 @@ void LatencyTrackerTest::assertReceivedTimelines(const std::vector<InputEventTim */ TEST_F(LatencyTrackerTest, TrackListener_DoesNotTriggerReporting) { mTracker->trackListener(/*inputEventId=*/1, /*isDown=*/false, /*eventTime=*/2, - /*readTime=*/3); + /*readTime=*/3, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN}); triggerEventReporting(/*eventTime=*/2); - assertReceivedTimeline(InputEventTimeline{false, 2, 3}); + assertReceivedTimeline(InputEventTimeline{/*isDown=*/false, /*eventTime=*/2, + /*readTime=*/3, /*vendorId=*/0, /*productID=*/0, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}}); } /** @@ -171,7 +204,8 @@ TEST_F(LatencyTrackerTest, TrackAllParameters_ReportsFullTimeline) { const auto& [connectionToken, expectedCT] = *expected.connectionTimelines.begin(); - mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime); + mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime, + DEVICE_ID, {InputDeviceUsageSource::UNKNOWN}); mTracker->trackFinishedEvent(inputEventId, connectionToken, expectedCT.deliveryTime, expectedCT.consumeTime, expectedCT.finishTime); mTracker->trackGraphicsLatency(inputEventId, connectionToken, expectedCT.graphicsTimeline); @@ -191,8 +225,10 @@ TEST_F(LatencyTrackerTest, WhenDuplicateEventsAreReported_DoesNotCrash) { // In the following 2 calls to trackListener, the inputEventId's are the same, but event times // are different. - mTracker->trackListener(inputEventId, isDown, /*eventTime=*/1, readTime); - mTracker->trackListener(inputEventId, isDown, /*eventTime=*/2, readTime); + mTracker->trackListener(inputEventId, isDown, /*eventTime=*/1, readTime, DEVICE_ID, + {InputDeviceUsageSource::UNKNOWN}); + mTracker->trackListener(inputEventId, isDown, /*eventTime=*/2, readTime, DEVICE_ID, + {InputDeviceUsageSource::UNKNOWN}); triggerEventReporting(/*eventTime=*/2); // Since we sent duplicate input events, the tracker should just delete all of them, because it @@ -205,7 +241,10 @@ TEST_F(LatencyTrackerTest, MultipleEvents_AreReportedConsistently) { InputEventTimeline timeline1( /*isDown*/ true, /*eventTime*/ 2, - /*readTime*/ 3); + /*readTime*/ 3, + /*vendorId=*/0, + /*productId=*/0, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}); timeline1.connectionTimelines.emplace(connection1, ConnectionTimeline(/*deliveryTime*/ 6, /*consumeTime*/ 7, /*finishTime*/ 8)); @@ -219,7 +258,10 @@ TEST_F(LatencyTrackerTest, MultipleEvents_AreReportedConsistently) { InputEventTimeline timeline2( /*isDown=*/false, /*eventTime=*/20, - /*readTime=*/30); + /*readTime=*/30, + /*vendorId=*/0, + /*productId=*/0, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}); timeline2.connectionTimelines.emplace(connection2, ConnectionTimeline(/*deliveryTime=*/60, /*consumeTime=*/70, @@ -232,10 +274,10 @@ TEST_F(LatencyTrackerTest, MultipleEvents_AreReportedConsistently) { // Start processing first event mTracker->trackListener(inputEventId1, timeline1.isDown, timeline1.eventTime, - timeline1.readTime); + timeline1.readTime, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN}); // Start processing second event mTracker->trackListener(inputEventId2, timeline2.isDown, timeline2.eventTime, - timeline2.readTime); + timeline2.readTime, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN}); mTracker->trackFinishedEvent(inputEventId1, connection1, connectionTimeline1.deliveryTime, connectionTimeline1.consumeTime, connectionTimeline1.finishTime); @@ -261,9 +303,11 @@ TEST_F(LatencyTrackerTest, IncompleteEvents_AreHandledConsistently) { for (size_t i = 1; i <= 100; i++) { mTracker->trackListener(/*inputEventId=*/i, timeline.isDown, timeline.eventTime, - timeline.readTime); - expectedTimelines.push_back( - InputEventTimeline{timeline.isDown, timeline.eventTime, timeline.readTime}); + timeline.readTime, /*deviceId=*/DEVICE_ID, + /*sources=*/{InputDeviceUsageSource::UNKNOWN}); + expectedTimelines.push_back(InputEventTimeline{timeline.isDown, timeline.eventTime, + timeline.readTime, timeline.vendorId, + timeline.productId, timeline.sources}); } // Now, complete the first event that was sent. mTracker->trackFinishedEvent(/*inputEventId=*/1, token, expectedCT.deliveryTime, @@ -289,10 +333,38 @@ TEST_F(LatencyTrackerTest, EventsAreTracked_WhenTrackListenerIsCalledFirst) { expectedCT.consumeTime, expectedCT.finishTime); mTracker->trackGraphicsLatency(inputEventId, connection1, expectedCT.graphicsTimeline); - mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime); + mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime, + DEVICE_ID, {InputDeviceUsageSource::UNKNOWN}); triggerEventReporting(expected.eventTime); - assertReceivedTimeline( - InputEventTimeline{expected.isDown, expected.eventTime, expected.readTime}); + assertReceivedTimeline(InputEventTimeline{expected.isDown, expected.eventTime, + expected.readTime, expected.vendorId, + expected.productId, expected.sources}); +} + +/** + * Check that LatencyTracker has the received timeline that contains the correctly + * resolved product ID, vendor ID and source for a particular device ID from + * among a list of devices. + */ +TEST_F(LatencyTrackerTest, TrackListenerCheck_DeviceInfoFieldsInputEventTimeline) { + constexpr int32_t inputEventId = 1; + InputEventTimeline timeline( + /*isDown*/ true, /*eventTime*/ 2, /*readTime*/ 3, + /*vendorId=*/50, /*productId=*/60, + /*sources=*/ + {InputDeviceUsageSource::TOUCHSCREEN, InputDeviceUsageSource::STYLUS_DIRECT}); + InputDeviceInfo deviceInfo1 = generateTestDeviceInfo( + /*vendorId=*/5, /*productId=*/6, /*deviceId=*/DEVICE_ID + 1); + InputDeviceInfo deviceInfo2 = generateTestDeviceInfo( + /*vendorId=*/50, /*productId=*/60, /*deviceId=*/DEVICE_ID); + + mTracker->setInputDevices({deviceInfo1, deviceInfo2}); + mTracker->trackListener(inputEventId, timeline.isDown, timeline.eventTime, timeline.readTime, + DEVICE_ID, + {InputDeviceUsageSource::TOUCHSCREEN, + InputDeviceUsageSource::STYLUS_DIRECT}); + triggerEventReporting(timeline.eventTime); + assertReceivedTimeline(timeline); } } // namespace android::inputdispatcher diff --git a/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp b/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp index 72780fb363..6daeaafbb3 100644 --- a/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp +++ b/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp @@ -15,6 +15,9 @@ */ #include <fuzzer/FuzzedDataProvider.h> +#include <linux/input.h> + +#include "../../InputDeviceMetricsSource.h" #include "dispatcher/LatencyTracker.h" namespace android { @@ -65,7 +68,11 @@ extern "C" int LLVMFuzzerTestOneInput(uint8_t* data, size_t size) { int32_t isDown = fdp.ConsumeBool(); nsecs_t eventTime = fdp.ConsumeIntegral<nsecs_t>(); nsecs_t readTime = fdp.ConsumeIntegral<nsecs_t>(); - tracker.trackListener(inputEventId, isDown, eventTime, readTime); + const DeviceId deviceId = fdp.ConsumeIntegral<int32_t>(); + std::set<InputDeviceUsageSource> sources = { + fdp.ConsumeEnum<InputDeviceUsageSource>()}; + tracker.trackListener(inputEventId, isDown, eventTime, readTime, deviceId, + sources); }, [&]() -> void { int32_t inputEventId = fdp.ConsumeIntegral<int32_t>(); |