Add LatencyTracker to InputDispatcher
LatencyTracker will be used to record the complete timeline of an input
event dispatch, from the kernel to the presentation of a graphics frame
to the display.
The data about input event timeline is coming from three different
locations:
1) notifyMotion: this is when the InputDispatcher first learns about the
event from InputReader. At this point, we learn the time when the event
was first created, to time when the event was read by the user space,
and we are now adding the timestamps when the InputReader notifies the
dispatcher about the event.
2) finishInputEvent: this is when the app sends an 'ack' that a specific
input event has been processed. Through this call, we learn about when
the event was first sent to the app, and when it was read by the app. At
this time, we are also collecting the 'finishTime', so that we can
measure the total time that the app spent processing the event.
3) sendTimeline: this is when the SurfaceFlinger notifies the app about
the metrics for a specific frame. This metrics information is passed
down through the InputChannel to the InputDispatcher. Here we learn
about the time when the app sent the buffer to the SurfaceFlinger
(gpuCompletedTime), and the time when the frame was presented
(presentTime).
Overall, the end-to-end touch latency is presentTime - eventTime.
The rest of the data can be used to measure the breakdown of this
latency.
The goal of LatencyTracker is to combine all this data and present a
complete, unified timeline for a specific input event for further data analysis.
In a separate CL, we will report this complete timeline to statsd.
Bug: 169866723
Test: atest inputflinger_tests
Change-Id: I6e6e80e3393878fe86f3935c7c0e13dfff8629f9
diff --git a/services/inputflinger/benchmarks/InputDispatcher_benchmarks.cpp b/services/inputflinger/benchmarks/InputDispatcher_benchmarks.cpp
index 1b5f1ab..bc77b8a 100644
--- a/services/inputflinger/benchmarks/InputDispatcher_benchmarks.cpp
+++ b/services/inputflinger/benchmarks/InputDispatcher_benchmarks.cpp
@@ -16,9 +16,11 @@
#include <benchmark/benchmark.h>
+#include <android/os/IInputConstants.h>
#include <binder/Binder.h>
#include "../dispatcher/InputDispatcher.h"
+using android::os::IInputConstants;
using android::os::InputEventInjectionResult;
using android::os::InputEventInjectionSync;
@@ -226,7 +228,7 @@
ui::Transform identityTransform;
MotionEvent event;
- event.initialize(InputEvent::nextId(), DEVICE_ID, AINPUT_SOURCE_TOUCHSCREEN,
+ event.initialize(IInputConstants::INVALID_INPUT_EVENT_ID, DEVICE_ID, AINPUT_SOURCE_TOUCHSCREEN,
ADISPLAY_ID_DEFAULT, INVALID_HMAC, AMOTION_EVENT_ACTION_DOWN,
/* actionButton */ 0, /* flags */ 0,
/* edgeFlags */ 0, AMETA_NONE, /* buttonState */ 0, MotionClassification::NONE,
@@ -252,9 +254,9 @@
const nsecs_t currentTime = now();
// Define a valid motion event.
- NotifyMotionArgs args(/* id */ 0, currentTime, currentTime, DEVICE_ID,
- AINPUT_SOURCE_TOUCHSCREEN, ADISPLAY_ID_DEFAULT, POLICY_FLAG_PASS_TO_USER,
- AMOTION_EVENT_ACTION_DOWN,
+ NotifyMotionArgs args(IInputConstants::INVALID_INPUT_EVENT_ID, currentTime, currentTime,
+ DEVICE_ID, AINPUT_SOURCE_TOUCHSCREEN, ADISPLAY_ID_DEFAULT,
+ POLICY_FLAG_PASS_TO_USER, AMOTION_EVENT_ACTION_DOWN,
/* actionButton */ 0, /* flags */ 0, AMETA_NONE, /* buttonState */ 0,
MotionClassification::NONE, AMOTION_EVENT_EDGE_FLAG_NONE, 1,
pointerProperties, pointerCoords,
@@ -283,14 +285,12 @@
for (auto _ : state) {
// Send ACTION_DOWN
motionArgs.action = AMOTION_EVENT_ACTION_DOWN;
- motionArgs.id = 0;
motionArgs.downTime = now();
motionArgs.eventTime = motionArgs.downTime;
dispatcher->notifyMotion(&motionArgs);
// Send ACTION_UP
motionArgs.action = AMOTION_EVENT_ACTION_UP;
- motionArgs.id = 1;
motionArgs.eventTime = now();
dispatcher->notifyMotion(&motionArgs);
diff --git a/services/inputflinger/dispatcher/Android.bp b/services/inputflinger/dispatcher/Android.bp
index 9750ef9..a9b594c 100644
--- a/services/inputflinger/dispatcher/Android.bp
+++ b/services/inputflinger/dispatcher/Android.bp
@@ -38,8 +38,10 @@
"InjectionState.cpp",
"InputDispatcher.cpp",
"InputDispatcherFactory.cpp",
+ "InputEventTimeline.cpp",
"InputState.cpp",
"InputTarget.cpp",
+ "LatencyTracker.cpp",
"Monitor.cpp",
"TouchState.cpp",
"DragState.cpp",
diff --git a/services/inputflinger/dispatcher/Entry.h b/services/inputflinger/dispatcher/Entry.h
index 45c5e24..a55cf68 100644
--- a/services/inputflinger/dispatcher/Entry.h
+++ b/services/inputflinger/dispatcher/Entry.h
@@ -79,7 +79,7 @@
explicit ConfigurationChangedEntry(int32_t id, nsecs_t eventTime);
std::string getDescription() const override;
- virtual ~ConfigurationChangedEntry();
+ ~ConfigurationChangedEntry() override;
};
struct DeviceResetEntry : EventEntry {
@@ -88,7 +88,7 @@
DeviceResetEntry(int32_t id, nsecs_t eventTime, int32_t deviceId);
std::string getDescription() const override;
- virtual ~DeviceResetEntry();
+ ~DeviceResetEntry() override;
};
struct FocusEntry : EventEntry {
@@ -100,7 +100,7 @@
const std::string& reason);
std::string getDescription() const override;
- virtual ~FocusEntry();
+ ~FocusEntry() override;
};
struct PointerCaptureChangedEntry : EventEntry {
@@ -109,7 +109,7 @@
PointerCaptureChangedEntry(int32_t id, nsecs_t eventTime, bool hasPointerCapture);
std::string getDescription() const override;
- virtual ~PointerCaptureChangedEntry();
+ ~PointerCaptureChangedEntry() override;
};
struct DragEntry : EventEntry {
@@ -153,7 +153,7 @@
std::string getDescription() const override;
void recycle();
- virtual ~KeyEntry();
+ ~KeyEntry() override;
};
struct MotionEntry : EventEntry {
@@ -204,7 +204,7 @@
std::vector<float> values);
std::string getDescription() const override;
- virtual ~SensorEntry();
+ ~SensorEntry() override;
};
// Tracks the progress of dispatching a particular event to a particular connection.
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index 6d5466a..f36aecf 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -446,6 +446,56 @@
return std::nullopt;
}
+static bool shouldReportMetricsForConnection(const Connection& connection) {
+ // Do not keep track of gesture monitors. They receive every event and would disproportionately
+ // affect the statistics.
+ if (connection.monitor) {
+ return false;
+ }
+ // If the connection is experiencing ANR, let's skip it. We have separate ANR metrics
+ if (!connection.responsive) {
+ return false;
+ }
+ return true;
+}
+
+static bool shouldReportFinishedEvent(const DispatchEntry& dispatchEntry,
+ const Connection& connection) {
+ const EventEntry& eventEntry = *dispatchEntry.eventEntry;
+ const int32_t& inputEventId = eventEntry.id;
+ if (inputEventId != dispatchEntry.resolvedEventId) {
+ // Event was transmuted
+ return false;
+ }
+ if (inputEventId == android::os::IInputConstants::INVALID_INPUT_EVENT_ID) {
+ return false;
+ }
+ // Only track latency for events that originated from hardware
+ if (eventEntry.isSynthesized()) {
+ return false;
+ }
+ const EventEntry::Type& inputEventEntryType = eventEntry.type;
+ if (inputEventEntryType == EventEntry::Type::KEY) {
+ const KeyEntry& keyEntry = static_cast<const KeyEntry&>(eventEntry);
+ if (keyEntry.flags & AKEY_EVENT_FLAG_CANCELED) {
+ return false;
+ }
+ } else if (inputEventEntryType == EventEntry::Type::MOTION) {
+ const MotionEntry& motionEntry = static_cast<const MotionEntry&>(eventEntry);
+ if (motionEntry.action == AMOTION_EVENT_ACTION_CANCEL ||
+ motionEntry.action == AMOTION_EVENT_ACTION_HOVER_EXIT) {
+ return false;
+ }
+ } else {
+ // Not a key or a motion
+ return false;
+ }
+ if (!shouldReportMetricsForConnection(connection)) {
+ return false;
+ }
+ return true;
+}
+
// --- InputDispatcher ---
InputDispatcher::InputDispatcher(const sp<InputDispatcherPolicyInterface>& policy)
@@ -467,6 +517,7 @@
mFocusedDisplayId(ADISPLAY_ID_DEFAULT),
mFocusedWindowRequestedPointerCapture(false),
mWindowTokenWithPointerCapture(nullptr),
+ mLatencyTracker(&mEmptyProcessor),
mCompatService(getCompatService()) {
mLooper = new Looper(false);
mReporter = createInputReporter();
@@ -2853,6 +2904,8 @@
"event",
connection->getInputChannelName().c_str());
#endif
+ // We keep the 'resolvedEventId' here equal to the original 'motionEntry.id' because
+ // this is a one-to-one event conversion.
dispatchEntry->resolvedAction = AMOTION_EVENT_ACTION_HOVER_ENTER;
}
@@ -3315,7 +3368,14 @@
finishDispatchCycleLocked(currentTime, connection, finish.seq, finish.handled,
finish.consumeTime);
} else if (std::holds_alternative<InputPublisher::Timeline>(*result)) {
- // TODO(b/167947340): Report this data to LatencyTracker
+ if (shouldReportMetricsForConnection(*connection)) {
+ const InputPublisher::Timeline& timeline =
+ std::get<InputPublisher::Timeline>(*result);
+ mLatencyTracker
+ .trackGraphicsLatency(timeline.inputEventId,
+ connection->inputChannel->getConnectionToken(),
+ std::move(timeline.graphicsTimeline));
+ }
}
gotOne = true;
}
@@ -3824,6 +3884,12 @@
args->xCursorPosition, args->yCursorPosition,
args->downTime, args->pointerCount,
args->pointerProperties, args->pointerCoords, 0, 0);
+ if (args->id != android::os::IInputConstants::INVALID_INPUT_EVENT_ID &&
+ 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);
+ }
needWake = enqueueInboundEventLocked(std::move(newEntry));
mLock.unlock();
@@ -5047,6 +5113,7 @@
dump += StringPrintf(INDENT2 "KeyRepeatDelay: %" PRId64 "ms\n", ns2ms(mConfig.keyRepeatDelay));
dump += StringPrintf(INDENT2 "KeyRepeatTimeout: %" PRId64 "ms\n",
ns2ms(mConfig.keyRepeatTimeout));
+ dump += mLatencyTracker.dump(INDENT2);
}
void InputDispatcher::dumpMonitors(std::string& dump, const std::vector<Monitor>& monitors) {
@@ -5620,10 +5687,12 @@
ALOGI("%s spent %" PRId64 "ms processing %s", connection->getWindowName().c_str(),
ns2ms(eventDuration), dispatchEntry->eventEntry->getDescription().c_str());
}
- // TODO(b/167947340): report event latency information to the policy
- // Example: mPolicy->reportFinishedEvent(commandEntry->eventId, eventEntry.eventTime,
- // dispatchEntry->deliveryTime, commandEntry->consumeTime,
- // finishTime);
+ if (shouldReportFinishedEvent(*dispatchEntry, *connection)) {
+ mLatencyTracker.trackFinishedEvent(dispatchEntry->eventEntry->id,
+ connection->inputChannel->getConnectionToken(),
+ dispatchEntry->deliveryTime, commandEntry->consumeTime,
+ finishTime);
+ }
bool restartEvent;
if (dispatchEntry->eventEntry->type == EventEntry::Type::KEY) {
diff --git a/services/inputflinger/dispatcher/InputDispatcher.h b/services/inputflinger/dispatcher/InputDispatcher.h
index dccbbb1..e592f42 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.h
+++ b/services/inputflinger/dispatcher/InputDispatcher.h
@@ -29,6 +29,7 @@
#include "InputState.h"
#include "InputTarget.h"
#include "InputThread.h"
+#include "LatencyTracker.h"
#include "Monitor.h"
#include "TouchState.h"
#include "TouchedWindow.h"
@@ -635,6 +636,13 @@
void doOnPointerDownOutsideFocusLockedInterruptible(CommandEntry* commandEntry) REQUIRES(mLock);
// Statistics gathering.
+ class EmptyTimelineProcessor : public InputEventTimelineProcessor {
+ void processTimeline(const InputEventTimeline& timeline) override {
+ // TODO(b/167947340): report latency information to the real aggregator
+ }
+ } mEmptyProcessor GUARDED_BY(mLock);
+
+ LatencyTracker mLatencyTracker GUARDED_BY(mLock);
void traceInboundQueueLengthLocked() REQUIRES(mLock);
void traceOutboundQueueLength(const Connection& connection);
void traceWaitQueueLength(const Connection& connection);
diff --git a/services/inputflinger/dispatcher/InputEventTimeline.cpp b/services/inputflinger/dispatcher/InputEventTimeline.cpp
new file mode 100644
index 0000000..3edb638
--- /dev/null
+++ b/services/inputflinger/dispatcher/InputEventTimeline.cpp
@@ -0,0 +1,86 @@
+/*
+ * Copyright (C) 2021 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 "InputEventTimeline.h"
+
+namespace android::inputdispatcher {
+
+ConnectionTimeline::ConnectionTimeline(nsecs_t deliveryTime, nsecs_t consumeTime,
+ nsecs_t finishTime)
+ : deliveryTime(deliveryTime),
+ consumeTime(consumeTime),
+ finishTime(finishTime),
+ mHasDispatchTimeline(true) {}
+
+ConnectionTimeline::ConnectionTimeline(std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline)
+ : graphicsTimeline(std::move(graphicsTimeline)), mHasGraphicsTimeline(true) {}
+
+bool ConnectionTimeline::isComplete() const {
+ return mHasDispatchTimeline && mHasGraphicsTimeline;
+}
+
+bool ConnectionTimeline::setDispatchTimeline(nsecs_t inDeliveryTime, nsecs_t inConsumeTime,
+ nsecs_t inFinishTime) {
+ if (mHasDispatchTimeline) {
+ return false;
+ }
+ deliveryTime = inDeliveryTime;
+ consumeTime = inConsumeTime;
+ finishTime = inFinishTime;
+ mHasDispatchTimeline = true;
+ return true;
+}
+
+bool ConnectionTimeline::setGraphicsTimeline(std::array<nsecs_t, GraphicsTimeline::SIZE> timeline) {
+ if (mHasGraphicsTimeline) {
+ return false;
+ }
+ graphicsTimeline = std::move(timeline);
+ mHasGraphicsTimeline = true;
+ return true;
+}
+
+bool ConnectionTimeline::operator==(const ConnectionTimeline& rhs) const {
+ return deliveryTime == rhs.deliveryTime && consumeTime == rhs.consumeTime &&
+ finishTime == rhs.finishTime && graphicsTimeline == rhs.graphicsTimeline &&
+ mHasDispatchTimeline == rhs.mHasDispatchTimeline &&
+ mHasGraphicsTimeline == rhs.mHasGraphicsTimeline;
+}
+
+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) {}
+
+bool InputEventTimeline::operator==(const InputEventTimeline& rhs) const {
+ if (connectionTimelines.size() != rhs.connectionTimelines.size()) {
+ return false;
+ }
+ for (const auto& [connectionToken, connectionTimeline] : connectionTimelines) {
+ auto it = rhs.connectionTimelines.find(connectionToken);
+ if (it == rhs.connectionTimelines.end()) {
+ return false;
+ }
+ if (connectionTimeline != it->second) {
+ return false;
+ }
+ }
+ return isDown == rhs.isDown && eventTime == rhs.eventTime && readTime == rhs.readTime;
+}
+
+} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/InputEventTimeline.h b/services/inputflinger/dispatcher/InputEventTimeline.h
new file mode 100644
index 0000000..77b8472
--- /dev/null
+++ b/services/inputflinger/dispatcher/InputEventTimeline.h
@@ -0,0 +1,108 @@
+/*
+ * Copyright (C) 2021 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.
+ */
+
+#ifndef _UI_INPUT_INPUTDISPATCHER_INPUTEVENTTIMELINE_H
+#define _UI_INPUT_INPUTDISPATCHER_INPUTEVENTTIMELINE_H
+
+#include <binder/IBinder.h>
+#include <input/Input.h>
+#include <unordered_map>
+
+namespace android {
+
+namespace inputdispatcher {
+
+/**
+ * Describes the input event timeline for each connection.
+ * An event with the same inputEventId can go to more than 1 connection simultaneously.
+ * For each connection that the input event goes to, there will be a separate ConnectionTimeline
+ * created.
+ * To create a complete ConnectionTimeline, we must receive two calls:
+ * 1) setDispatchTimeline
+ * 2) setGraphicsTimeline
+ *
+ * In a typical scenario, the dispatch timeline is known first. Later, if a frame is produced, the
+ * graphics timeline is available.
+ */
+struct ConnectionTimeline {
+ // DispatchTimeline
+ nsecs_t deliveryTime; // time at which the event was sent to the receiver
+ nsecs_t consumeTime; // time at which the receiver read the event
+ nsecs_t finishTime; // time at which the finish event was received
+ // GraphicsTimeline
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+
+ ConnectionTimeline(nsecs_t deliveryTime, nsecs_t consumeTime, nsecs_t finishTime);
+ ConnectionTimeline(std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline);
+
+ /**
+ * True if all contained timestamps are valid, false otherwise.
+ */
+ bool isComplete() const;
+ /**
+ * Set the dispatching-related times. Return true if the operation succeeded, false if the
+ * dispatching times have already been set. If this function returns false, it likely indicates
+ * an error from the app side.
+ */
+ bool setDispatchTimeline(nsecs_t deliveryTime, nsecs_t consumeTime, nsecs_t finishTime);
+ /**
+ * Set the graphics-related times. Return true if the operation succeeded, false if the
+ * graphics times have already been set. If this function returns false, it likely indicates
+ * an error from the app side.
+ */
+ bool setGraphicsTimeline(std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline);
+
+ inline bool operator==(const ConnectionTimeline& rhs) const;
+ inline bool operator!=(const ConnectionTimeline& rhs) const;
+
+private:
+ bool mHasDispatchTimeline = false;
+ bool mHasGraphicsTimeline = false;
+};
+
+struct InputEventTimeline {
+ InputEventTimeline(bool isDown, nsecs_t eventTime, nsecs_t readTime);
+ const bool isDown; // True if this is an ACTION_DOWN event
+ const nsecs_t eventTime;
+ const nsecs_t readTime;
+
+ struct IBinderHash {
+ std::size_t operator()(const sp<IBinder>& b) const {
+ return std::hash<IBinder*>{}(b.get());
+ }
+ };
+
+ std::unordered_map<sp<IBinder>, ConnectionTimeline, IBinderHash> connectionTimelines;
+
+ bool operator==(const InputEventTimeline& rhs) const;
+};
+
+class InputEventTimelineProcessor {
+protected:
+ InputEventTimelineProcessor() {}
+ virtual ~InputEventTimelineProcessor() {}
+
+public:
+ /**
+ * Process the provided timeline
+ */
+ virtual void processTimeline(const InputEventTimeline& timeline) = 0;
+};
+
+} // namespace inputdispatcher
+} // namespace android
+
+#endif // _UI_INPUT_INPUTDISPATCHER_INPUTEVENTTIMELINE_H
diff --git a/services/inputflinger/dispatcher/LatencyTracker.cpp b/services/inputflinger/dispatcher/LatencyTracker.cpp
new file mode 100644
index 0000000..d634dcd
--- /dev/null
+++ b/services/inputflinger/dispatcher/LatencyTracker.cpp
@@ -0,0 +1,183 @@
+/*
+ * Copyright (C) 2021 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.
+ */
+
+#define LOG_TAG "LatencyTracker"
+#include "LatencyTracker.h"
+
+#include <inttypes.h>
+
+#include <android-base/properties.h>
+#include <android-base/stringprintf.h>
+#include <android/os/IInputConstants.h>
+#include <input/Input.h>
+#include <log/log.h>
+
+using android::base::HwTimeoutMultiplier;
+using android::base::StringPrintf;
+
+namespace android::inputdispatcher {
+
+/**
+ * Events that are older than this time will be considered mature, at which point we will stop
+ * waiting for the apps to provide further information about them.
+ * It's likely that the apps will ANR if the events are not received by this deadline, and we
+ * already track ANR metrics separately.
+ */
+const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds(
+ android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS *
+ HwTimeoutMultiplier());
+
+static bool isMatureEvent(nsecs_t eventTime, nsecs_t now) {
+ std::chrono::duration age = std::chrono::nanoseconds(now) - std::chrono::nanoseconds(eventTime);
+ return age > ANR_TIMEOUT;
+}
+
+/**
+ * A multimap allows to have several entries with the same key. This function just erases a specific
+ * key-value pair. Equivalent to the imaginary std api std::multimap::erase(key, value).
+ */
+template <typename K, typename V>
+static void eraseByKeyAndValue(std::multimap<K, V>& map, K key, V value) {
+ auto iterpair = map.equal_range(key);
+
+ for (auto it = iterpair.first; it != iterpair.second; ++it) {
+ if (it->second == value) {
+ map.erase(it);
+ break;
+ }
+ }
+}
+
+LatencyTracker::LatencyTracker(InputEventTimelineProcessor* processor)
+ : mTimelineProcessor(processor) {
+ LOG_ALWAYS_FATAL_IF(processor == nullptr);
+}
+
+void LatencyTracker::trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime,
+ nsecs_t readTime) {
+ reportAndPruneMatureRecords(eventTime);
+ const auto it = mTimelines.find(inputEventId);
+ if (it != mTimelines.end()) {
+ // Input event ids are randomly generated, so it's possible that two events have the same
+ // event id. Drop this event, and also drop the existing event because the apps would
+ // confuse us by reporting the rest of the timeline for one of them. This should happen
+ // rarely, so we won't lose much data
+ mTimelines.erase(it);
+ // In case we have another input event with a different id and at the same eventTime,
+ // only erase this specific inputEventId.
+ eraseByKeyAndValue(mEventTimes, eventTime, inputEventId);
+ return;
+ }
+ mTimelines.emplace(inputEventId, InputEventTimeline(isDown, eventTime, readTime));
+ mEventTimes.emplace(eventTime, inputEventId);
+}
+
+void LatencyTracker::trackFinishedEvent(int32_t inputEventId, const sp<IBinder>& connectionToken,
+ nsecs_t deliveryTime, nsecs_t consumeTime,
+ nsecs_t finishTime) {
+ const auto it = mTimelines.find(inputEventId);
+ if (it == mTimelines.end()) {
+ // It's possible that an app sends a bad (or late)'Finish' signal, since it's free to do
+ // anything in its process. Just drop the report and move on.
+ return;
+ }
+
+ InputEventTimeline& timeline = it->second;
+ const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
+ if (connectionIt == timeline.connectionTimelines.end()) {
+ // Most likely case: app calls 'finishInputEvent' before it reports the graphics timeline
+ timeline.connectionTimelines.emplace(connectionToken,
+ ConnectionTimeline{deliveryTime, consumeTime,
+ finishTime});
+ } else {
+ // Already have a record for this connectionToken
+ ConnectionTimeline& connectionTimeline = connectionIt->second;
+ const bool success =
+ connectionTimeline.setDispatchTimeline(deliveryTime, consumeTime, finishTime);
+ if (!success) {
+ // We are receiving unreliable data from the app. Just delete the entire connection
+ // timeline for this event
+ timeline.connectionTimelines.erase(connectionIt);
+ }
+ }
+}
+
+void LatencyTracker::trackGraphicsLatency(
+ int32_t inputEventId, const sp<IBinder>& connectionToken,
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline) {
+ const auto it = mTimelines.find(inputEventId);
+ if (it == mTimelines.end()) {
+ // It's possible that an app sends a bad (or late) 'Timeline' signal, since it's free to do
+ // anything in its process. Just drop the report and move on.
+ return;
+ }
+
+ InputEventTimeline& timeline = it->second;
+ const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
+ if (connectionIt == timeline.connectionTimelines.end()) {
+ timeline.connectionTimelines.emplace(connectionToken, std::move(graphicsTimeline));
+ } else {
+ // Most likely case
+ ConnectionTimeline& connectionTimeline = connectionIt->second;
+ const bool success = connectionTimeline.setGraphicsTimeline(std::move(graphicsTimeline));
+ if (!success) {
+ // We are receiving unreliable data from the app. Just delete the entire connection
+ // timeline for this event
+ timeline.connectionTimelines.erase(connectionIt);
+ }
+ }
+}
+
+/**
+ * We should use the current time 'now()' here to determine the age of the event, but instead we
+ * are using the latest 'eventTime' for efficiency since this time is already acquired, and
+ * 'trackListener' should happen soon after the event occurs.
+ */
+void LatencyTracker::reportAndPruneMatureRecords(nsecs_t newEventTime) {
+ while (!mEventTimes.empty()) {
+ const auto& [oldestEventTime, oldestInputEventId] = *mEventTimes.begin();
+ if (isMatureEvent(oldestEventTime, newEventTime /*now*/)) {
+ // Report and drop this event
+ const auto it = mTimelines.find(oldestInputEventId);
+ LOG_ALWAYS_FATAL_IF(it == mTimelines.end(),
+ "Event %" PRId32 " is in mEventTimes, but not in mTimelines",
+ oldestInputEventId);
+ const InputEventTimeline& timeline = it->second;
+ mTimelineProcessor->processTimeline(timeline);
+ mTimelines.erase(it);
+ mEventTimes.erase(mEventTimes.begin());
+ } else {
+ // If the oldest event does not need to be pruned, no events should be pruned.
+ return;
+ }
+ }
+}
+
+void LatencyTracker::reportNow() {
+ for (const auto& [inputEventId, timeline] : mTimelines) {
+ mTimelineProcessor->processTimeline(timeline);
+ }
+ mTimelines.clear();
+ mEventTimes.clear();
+}
+
+std::string LatencyTracker::dump(const char* prefix) {
+ return StringPrintf("%sLatencyTracker:\n", prefix) +
+ StringPrintf("%s mTimelines.size() = %zu\n", prefix, mTimelines.size()) +
+ StringPrintf("%s mEventTimes.size() = %zu\n", prefix, mEventTimes.size());
+}
+
+} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/LatencyTracker.h b/services/inputflinger/dispatcher/LatencyTracker.h
new file mode 100644
index 0000000..289b8ed
--- /dev/null
+++ b/services/inputflinger/dispatcher/LatencyTracker.h
@@ -0,0 +1,87 @@
+/*
+ * Copyright (C) 2021 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.
+ */
+
+#ifndef _UI_INPUT_INPUTDISPATCHER_LATENCYTRACKER_H
+#define _UI_INPUT_INPUTDISPATCHER_LATENCYTRACKER_H
+
+#include <map>
+#include <unordered_map>
+
+#include <binder/IBinder.h>
+#include <input/Input.h>
+
+#include "InputEventTimeline.h"
+
+namespace android::inputdispatcher {
+
+/**
+ * Maintain a record for input events that are received by InputDispatcher, sent out to the apps,
+ * and processed by the apps. Once an event becomes "mature" (older than the ANR timeout), report
+ * the entire input event latency history to the reporting function.
+ *
+ * All calls to LatencyTracker should come from the same thread. It is not thread-safe.
+ */
+class LatencyTracker {
+public:
+ /**
+ * Create a LatencyTracker.
+ * param reportingFunction: the function that will be called in order to report full latency.
+ */
+ LatencyTracker(InputEventTimelineProcessor* processor);
+ /**
+ * Start keeping track of an event identified by inputEventId. This must be called first.
+ */
+ void trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime, nsecs_t readTime);
+ 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);
+
+ /**
+ * Report all collected events immediately, even if some of them are currently incomplete
+ * and may receive 'trackFinishedEvent' or 'trackGraphicsLatency' calls in the future.
+ * This is useful for tests. Otherwise, tests would have to inject additional "future" events,
+ * which is not convenient.
+ */
+ void reportNow();
+
+ std::string dump(const char* prefix);
+
+private:
+ /**
+ * A collection of InputEventTimelines keyed by inputEventId. An InputEventTimeline is first
+ * created when 'trackListener' is called.
+ * When either 'trackFinishedEvent' or 'trackGraphicsLatency' is called for this input event,
+ * the corresponding InputEventTimeline will be updated for that token.
+ */
+ std::unordered_map<int32_t /*inputEventId*/, InputEventTimeline> mTimelines;
+ /**
+ * The collection of eventTimes will help us quickly find the events that we should prune
+ * from the 'mTimelines'. Since 'mTimelines' is keyed by inputEventId, it would be inefficient
+ * to walk through it directly to find the oldest input events to get rid of.
+ * There is a 1:1 mapping between 'mTimelines' and 'mEventTimes'.
+ * We are using 'multimap' instead of 'map' because there could be more than 1 event with the
+ * same eventTime.
+ */
+ std::multimap<nsecs_t /*eventTime*/, int32_t /*inputEventId*/> mEventTimes;
+
+ InputEventTimelineProcessor* mTimelineProcessor;
+ void reportAndPruneMatureRecords(nsecs_t newEventTime);
+};
+
+} // namespace android::inputdispatcher
+
+#endif // _UI_INPUT_INPUTDISPATCHER_LATENCYTRACKER_H
diff --git a/services/inputflinger/tests/Android.bp b/services/inputflinger/tests/Android.bp
index 42b54c7..918e1be 100644
--- a/services/inputflinger/tests/Android.bp
+++ b/services/inputflinger/tests/Android.bp
@@ -46,6 +46,7 @@
"InputDispatcher_test.cpp",
"InputReader_test.cpp",
"InputFlingerService_test.cpp",
+ "LatencyTracker_test.cpp",
"TestInputListener.cpp",
"UinputDevice.cpp",
],
diff --git a/services/inputflinger/tests/InputDispatcher_test.cpp b/services/inputflinger/tests/InputDispatcher_test.cpp
index 855453e..93aa6ac 100644
--- a/services/inputflinger/tests/InputDispatcher_test.cpp
+++ b/services/inputflinger/tests/InputDispatcher_test.cpp
@@ -441,7 +441,7 @@
sp<FakeInputDispatcherPolicy> mFakePolicy;
sp<InputDispatcher> mDispatcher;
- virtual void SetUp() override {
+ void SetUp() override {
mFakePolicy = new FakeInputDispatcherPolicy();
mDispatcher = new InputDispatcher(mFakePolicy);
mDispatcher->setInputDispatchMode(/*enabled*/ true, /*frozen*/ false);
@@ -449,7 +449,7 @@
ASSERT_EQ(OK, mDispatcher->start());
}
- virtual void TearDown() override {
+ void TearDown() override {
ASSERT_EQ(OK, mDispatcher->stop());
mFakePolicy.clear();
mDispatcher.clear();
diff --git a/services/inputflinger/tests/LatencyTracker_test.cpp b/services/inputflinger/tests/LatencyTracker_test.cpp
new file mode 100644
index 0000000..e7e1937
--- /dev/null
+++ b/services/inputflinger/tests/LatencyTracker_test.cpp
@@ -0,0 +1,253 @@
+/*
+ * Copyright (C) 2021 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 "../dispatcher/LatencyTracker.h"
+
+#include <binder/Binder.h>
+#include <gtest/gtest.h>
+#include <inttypes.h>
+#include <log/log.h>
+
+#define TAG "LatencyTracker_test"
+
+using android::inputdispatcher::InputEventTimeline;
+using android::inputdispatcher::LatencyTracker;
+
+namespace android::inputdispatcher {
+
+InputEventTimeline getTestTimeline() {
+ InputEventTimeline t(
+ /*isDown*/ true,
+ /*eventTime*/ 2,
+ /*readTime*/ 3);
+ ConnectionTimeline expectedCT(/*deliveryTime*/ 6, /* consumeTime*/ 7, /*finishTime*/ 8);
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+ graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 9;
+ graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 10;
+ expectedCT.setGraphicsTimeline(std::move(graphicsTimeline));
+ t.connectionTimelines.emplace(new BBinder(), std::move(expectedCT));
+ return t;
+}
+
+// --- LatencyTrackerTest ---
+class LatencyTrackerTest : public testing::Test, public InputEventTimelineProcessor {
+protected:
+ std::unique_ptr<LatencyTracker> mTracker;
+ sp<IBinder> connection1;
+ sp<IBinder> connection2;
+
+ void SetUp() override {
+ connection1 = new BBinder();
+ connection2 = new BBinder();
+
+ mTracker = std::make_unique<LatencyTracker>(this);
+ }
+ void TearDown() override {}
+
+ void assertReceivedTimeline(const InputEventTimeline& timeline);
+ /**
+ * Timelines can be received in any order (order is not guaranteed). So if we are expecting more
+ * than 1 timeline, use this function to check that the set of received timelines matches
+ * what we expected.
+ */
+ void assertReceivedTimelines(const std::vector<InputEventTimeline>& timelines);
+
+private:
+ void processTimeline(const InputEventTimeline& timeline) override {
+ mReceivedTimelines.push_back(timeline);
+ }
+ std::deque<InputEventTimeline> mReceivedTimelines;
+};
+
+void LatencyTrackerTest::assertReceivedTimeline(const InputEventTimeline& timeline) {
+ mTracker->reportNow();
+ ASSERT_FALSE(mReceivedTimelines.empty());
+ const InputEventTimeline& t = mReceivedTimelines.front();
+ ASSERT_EQ(timeline, t);
+ mReceivedTimelines.pop_front();
+}
+
+/**
+ * We are essentially comparing two multisets, but without constructing them.
+ * This comparison is inefficient, but it avoids having to construct a set, and also avoids the
+ * declaration of copy constructor for ConnectionTimeline.
+ * We ensure that collections A and B have the same size, that for every element in A, there is an
+ * equal element in B, and for every element in B there is an equal element in A.
+ */
+void LatencyTrackerTest::assertReceivedTimelines(const std::vector<InputEventTimeline>& timelines) {
+ mTracker->reportNow();
+ ASSERT_EQ(timelines.size(), mReceivedTimelines.size());
+ for (const InputEventTimeline& expectedTimeline : timelines) {
+ bool found = false;
+ for (const InputEventTimeline& receivedTimeline : mReceivedTimelines) {
+ if (receivedTimeline == expectedTimeline) {
+ found = true;
+ break;
+ }
+ }
+ ASSERT_TRUE(found) << "Could not find expected timeline with eventTime="
+ << expectedTimeline.eventTime;
+ }
+ for (const InputEventTimeline& receivedTimeline : mReceivedTimelines) {
+ bool found = false;
+ for (const InputEventTimeline& expectedTimeline : timelines) {
+ if (receivedTimeline == expectedTimeline) {
+ found = true;
+ break;
+ }
+ }
+ ASSERT_TRUE(found) << "Could not find received timeline with eventTime="
+ << receivedTimeline.eventTime;
+ }
+ mReceivedTimelines.clear();
+}
+
+/**
+ * Ensure that calling 'trackListener' in isolation only creates an inputflinger timeline, without
+ * any additional ConnectionTimeline's.
+ */
+TEST_F(LatencyTrackerTest, TrackListener_DoesNotTriggerReporting) {
+ mTracker->trackListener(1 /*inputEventId*/, false /*isDown*/, 2 /*eventTime*/, 3 /*readTime*/);
+ assertReceivedTimeline(InputEventTimeline{false, 2, 3});
+}
+
+/**
+ * A single call to trackFinishedEvent should not cause a timeline to be reported.
+ */
+TEST_F(LatencyTrackerTest, TrackFinishedEvent_DoesNotTriggerReporting) {
+ mTracker->trackFinishedEvent(1 /*inputEventId*/, connection1, 2 /*deliveryTime*/,
+ 3 /*consumeTime*/, 4 /*finishTime*/);
+ assertReceivedTimelines({});
+}
+
+/**
+ * A single call to trackGraphicsLatency should not cause a timeline to be reported.
+ */
+TEST_F(LatencyTrackerTest, TrackGraphicsLatency_DoesNotTriggerReporting) {
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
+ graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 2;
+ graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 3;
+ mTracker->trackGraphicsLatency(1 /*inputEventId*/, connection2, graphicsTimeline);
+ assertReceivedTimelines({});
+}
+
+TEST_F(LatencyTrackerTest, TrackAllParameters_ReportsFullTimeline) {
+ constexpr int32_t inputEventId = 1;
+ InputEventTimeline expected = getTestTimeline();
+
+ const auto& [connectionToken, expectedCT] = *expected.connectionTimelines.begin();
+
+ mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime);
+ mTracker->trackFinishedEvent(inputEventId, connectionToken, expectedCT.deliveryTime,
+ expectedCT.consumeTime, expectedCT.finishTime);
+ mTracker->trackGraphicsLatency(inputEventId, connectionToken, expectedCT.graphicsTimeline);
+
+ assertReceivedTimeline(expected);
+}
+
+TEST_F(LatencyTrackerTest, MultipleEvents_AreReportedConsistently) {
+ constexpr int32_t inputEventId1 = 1;
+ InputEventTimeline timeline1(
+ /*isDown*/ true,
+ /*eventTime*/ 2,
+ /*readTime*/ 3);
+ timeline1.connectionTimelines.emplace(connection1,
+ ConnectionTimeline(/*deliveryTime*/ 6, /*consumeTime*/ 7,
+ /*finishTime*/ 8));
+ ConnectionTimeline& connectionTimeline1 = timeline1.connectionTimelines.begin()->second;
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline1;
+ graphicsTimeline1[GraphicsTimeline::GPU_COMPLETED_TIME] = 9;
+ graphicsTimeline1[GraphicsTimeline::PRESENT_TIME] = 10;
+ connectionTimeline1.setGraphicsTimeline(std::move(graphicsTimeline1));
+
+ constexpr int32_t inputEventId2 = 10;
+ InputEventTimeline timeline2(
+ /*isDown*/ false,
+ /*eventTime*/ 20,
+ /*readTime*/ 30);
+ timeline2.connectionTimelines.emplace(connection2,
+ ConnectionTimeline(/*deliveryTime*/ 60,
+ /*consumeTime*/ 70,
+ /*finishTime*/ 80));
+ ConnectionTimeline& connectionTimeline2 = timeline2.connectionTimelines.begin()->second;
+ std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline2;
+ graphicsTimeline2[GraphicsTimeline::GPU_COMPLETED_TIME] = 90;
+ graphicsTimeline2[GraphicsTimeline::PRESENT_TIME] = 100;
+ connectionTimeline2.setGraphicsTimeline(std::move(graphicsTimeline2));
+
+ // Start processing first event
+ mTracker->trackListener(inputEventId1, timeline1.isDown, timeline1.eventTime,
+ timeline1.readTime);
+ // Start processing second event
+ mTracker->trackListener(inputEventId2, timeline2.isDown, timeline2.eventTime,
+ timeline2.readTime);
+ mTracker->trackFinishedEvent(inputEventId1, connection1, connectionTimeline1.deliveryTime,
+ connectionTimeline1.consumeTime, connectionTimeline1.finishTime);
+
+ mTracker->trackFinishedEvent(inputEventId2, connection2, connectionTimeline2.deliveryTime,
+ connectionTimeline2.consumeTime, connectionTimeline2.finishTime);
+ mTracker->trackGraphicsLatency(inputEventId1, connection1,
+ connectionTimeline1.graphicsTimeline);
+ mTracker->trackGraphicsLatency(inputEventId2, connection2,
+ connectionTimeline2.graphicsTimeline);
+ // Now both events should be completed
+ assertReceivedTimelines({timeline1, timeline2});
+}
+
+/**
+ * Check that LatencyTracker consistently tracks events even if there are many incomplete events.
+ */
+TEST_F(LatencyTrackerTest, IncompleteEvents_AreHandledConsistently) {
+ InputEventTimeline timeline = getTestTimeline();
+ std::vector<InputEventTimeline> expectedTimelines;
+ const ConnectionTimeline& expectedCT = timeline.connectionTimelines.begin()->second;
+ const sp<IBinder>& token = timeline.connectionTimelines.begin()->first;
+
+ for (size_t i = 1; i <= 100; i++) {
+ mTracker->trackListener(i /*inputEventId*/, timeline.isDown, timeline.eventTime,
+ timeline.readTime);
+ expectedTimelines.push_back(
+ InputEventTimeline{timeline.isDown, timeline.eventTime, timeline.readTime});
+ }
+ // Now, complete the first event that was sent.
+ mTracker->trackFinishedEvent(1 /*inputEventId*/, token, expectedCT.deliveryTime,
+ expectedCT.consumeTime, expectedCT.finishTime);
+ mTracker->trackGraphicsLatency(1 /*inputEventId*/, token, expectedCT.graphicsTimeline);
+
+ expectedTimelines[0].connectionTimelines.emplace(token, std::move(expectedCT));
+ assertReceivedTimelines(expectedTimelines);
+}
+
+/**
+ * For simplicity of the implementation, LatencyTracker only starts tracking an event when
+ * 'trackListener' is invoked.
+ * Both 'trackFinishedEvent' and 'trackGraphicsLatency' should not start a new event.
+ * If they are received before 'trackListener' (which should not be possible), they are ignored.
+ */
+TEST_F(LatencyTrackerTest, EventsAreTracked_WhenTrackListenerIsCalledFirst) {
+ constexpr int32_t inputEventId = 1;
+ InputEventTimeline expected = getTestTimeline();
+ const ConnectionTimeline& expectedCT = expected.connectionTimelines.begin()->second;
+ mTracker->trackFinishedEvent(inputEventId, connection1, expectedCT.deliveryTime,
+ expectedCT.consumeTime, expectedCT.finishTime);
+ mTracker->trackGraphicsLatency(inputEventId, connection1, expectedCT.graphicsTimeline);
+
+ mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime);
+ assertReceivedTimeline(
+ InputEventTimeline{expected.isDown, expected.eventTime, expected.readTime});
+}
+
+} // namespace android::inputdispatcher