summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
author jioana <jioana@google.com> 2024-09-10 10:13:27 +0000
committer Ioana Jianu <jioana@google.com> 2024-09-23 16:44:06 +0000
commit24878b59e32e3f3bac569ea10c8118186094765c (patch)
treecf22813706a21496e29a90e30bd5167376c189cd
parentde3019c89c0cd6d24f9f2037ad60fa57a2a9345e (diff)
LatencyAggregatorWithHistograms for InputEventLatencyReported atom.
Currently, input latency metrics cannot be reported on a per-device/per -source/per-input-event-type granular level. Moreover, regarding implementation, the input event latencies are aggregated into KLL sketches (per day) and serialized into the InputEventLatencySketch, which is a pulled atom, using LatencyAggregator. This means that only 20,000 input event latencies can be recorded per day, the rest are dropped. We want to capture latency statistics that can be broken down by per input device (characterized by its Product ID and Vendor ID), by source(s) of the input event (such as stylus, touchpad, touchscreen) and by specific types of input events (such as MOTION_ACTION_DOWN, MOTION_ACTION_UP, MOTION_ACTION_MOVE, KEY). The logic for per device input latency metrics lives in LatencyAggregatorWithHistograms. Once the flag is rolled out, this will replace LatencyAggregator. Input events with the same identifier are mapped to an array of 7 histograms. Each histogram's bin sizes are custom to the latency stage and input event type. When an input event timeline is received, the relevant bin counter of the corresponding histogram is incremented. The InputEventLatencyReported atom is pushed every 6 hours by calling pushLatencyStatistics from InputDispatcher DispatchOnce. After a push, histograms are cleared. processSlowEvent was copied from LatencyAggregator to keep logging the SLOW_iNPUT_EVENT_REPORTED atom. Tests will be added in a separate CL. Bug: 270049345 Test: atest inputflinger_tests Test: manual tests with statsd_testdrive 932 Flag: com.android.input.flags.enable_per_device_input_latency_metrics Change-Id: I64fb883f4a01889b3600043d21446613a5a5bce7
-rw-r--r--services/inputflinger/dispatcher/Android.bp1
-rw-r--r--services/inputflinger/dispatcher/InputDispatcher.cpp35
-rw-r--r--services/inputflinger/dispatcher/InputDispatcher.h5
-rw-r--r--services/inputflinger/dispatcher/InputEventTimeline.h10
-rw-r--r--services/inputflinger/dispatcher/LatencyAggregator.cpp7
-rw-r--r--services/inputflinger/dispatcher/LatencyAggregator.h2
-rw-r--r--services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.cpp345
-rw-r--r--services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.h164
-rw-r--r--services/inputflinger/dispatcher/LatencyTracker.cpp6
-rw-r--r--services/inputflinger/dispatcher/LatencyTracker.h2
-rw-r--r--services/inputflinger/tests/LatencyTracker_test.cpp4
-rw-r--r--services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp6
12 files changed, 575 insertions, 12 deletions
diff --git a/services/inputflinger/dispatcher/Android.bp b/services/inputflinger/dispatcher/Android.bp
index 1a0ec48525..8b2b8432c3 100644
--- a/services/inputflinger/dispatcher/Android.bp
+++ b/services/inputflinger/dispatcher/Android.bp
@@ -46,6 +46,7 @@ filegroup {
"InputState.cpp",
"InputTarget.cpp",
"LatencyAggregator.cpp",
+ "LatencyAggregatorWithHistograms.cpp",
"LatencyTracker.cpp",
"Monitor.cpp",
"TouchedWindow.cpp",
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index 250e72cfa8..da3ac20241 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -155,6 +155,10 @@ constexpr std::chrono::milliseconds SLOW_INTERCEPTION_THRESHOLD = 50ms;
// Number of recent events to keep for debugging purposes.
constexpr size_t RECENT_QUEUE_MAX_SIZE = 10;
+// Interval at which we should push the atom gathering input event latencies in
+// LatencyAggregatorWithHistograms
+constexpr nsecs_t LATENCY_STATISTICS_PUSH_INTERVAL = 6 * 3600 * 1000000000LL; // 6 hours
+
// Event log tags. See EventLogTags.logtags for reference.
constexpr int LOGTAG_INPUT_INTERACTION = 62000;
constexpr int LOGTAG_INPUT_FOCUS = 62001;
@@ -944,8 +948,13 @@ InputDispatcher::InputDispatcher(InputDispatcherPolicyInterface& policy,
mFocusedDisplayId(ui::LogicalDisplayId::DEFAULT),
mWindowTokenWithPointerCapture(nullptr),
mAwaitedApplicationDisplayId(ui::LogicalDisplayId::INVALID),
- mLatencyAggregator(),
- mLatencyTracker(&mLatencyAggregator) {
+ mInputEventTimelineProcessor(
+ input_flags::enable_per_device_input_latency_metrics()
+ ? std::move(std::unique_ptr<InputEventTimelineProcessor>(
+ new LatencyAggregatorWithHistograms()))
+ : std::move(std::unique_ptr<InputEventTimelineProcessor>(
+ new LatencyAggregator()))),
+ mLatencyTracker(*mInputEventTimelineProcessor) {
mLooper = sp<Looper>::make(false);
mReporter = createInputReporter();
@@ -1017,6 +1026,11 @@ void InputDispatcher::dispatchOnce() {
const nsecs_t nextAnrCheck = processAnrsLocked();
nextWakeupTime = std::min(nextWakeupTime, nextAnrCheck);
+ if (input_flags::enable_per_device_input_latency_metrics()) {
+ const nsecs_t nextStatisticsPush = processLatencyStatisticsLocked();
+ nextWakeupTime = std::min(nextWakeupTime, nextStatisticsPush);
+ }
+
// We are about to enter an infinitely long sleep, because we have no commands or
// pending or queued events
if (nextWakeupTime == LLONG_MAX) {
@@ -1097,6 +1111,21 @@ nsecs_t InputDispatcher::processAnrsLocked() {
return LLONG_MIN;
}
+/**
+ * Check if enough time has passed since the last latency statistics push.
+ * Return the time at which we should wake up next.
+ */
+nsecs_t InputDispatcher::processLatencyStatisticsLocked() {
+ const nsecs_t currentTime = now();
+ // Log the atom recording latency statistics if more than 6 hours passed from the last
+ // push
+ if (currentTime - mLastStatisticPushTime >= LATENCY_STATISTICS_PUSH_INTERVAL) {
+ mInputEventTimelineProcessor->pushLatencyStatistics();
+ mLastStatisticPushTime = currentTime;
+ }
+ return mLastStatisticPushTime + LATENCY_STATISTICS_PUSH_INTERVAL;
+}
+
std::chrono::nanoseconds InputDispatcher::getDispatchingTimeoutLocked(
const std::shared_ptr<Connection>& connection) {
if (connection->monitor) {
@@ -6055,7 +6084,7 @@ void InputDispatcher::dumpDispatchStateLocked(std::string& dump) const {
dump += StringPrintf(INDENT2 "KeyRepeatTimeout: %" PRId64 "ms\n",
ns2ms(mConfig.keyRepeatTimeout));
dump += mLatencyTracker.dump(INDENT2);
- dump += mLatencyAggregator.dump(INDENT2);
+ dump += mInputEventTimelineProcessor->dump(INDENT2);
dump += INDENT "InputTracer: ";
dump += mTracer == nullptr ? "Disabled" : "Enabled";
}
diff --git a/services/inputflinger/dispatcher/InputDispatcher.h b/services/inputflinger/dispatcher/InputDispatcher.h
index 87dfd1d8a4..7060efacf7 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.h
+++ b/services/inputflinger/dispatcher/InputDispatcher.h
@@ -28,6 +28,7 @@
#include "InputTarget.h"
#include "InputThread.h"
#include "LatencyAggregator.h"
+#include "LatencyAggregatorWithHistograms.h"
#include "LatencyTracker.h"
#include "Monitor.h"
#include "TouchState.h"
@@ -326,6 +327,7 @@ private:
std::chrono::nanoseconds mMonitorDispatchingTimeout GUARDED_BY(mLock);
nsecs_t processAnrsLocked() REQUIRES(mLock);
+ nsecs_t processLatencyStatisticsLocked() REQUIRES(mLock);
std::chrono::nanoseconds getDispatchingTimeoutLocked(
const std::shared_ptr<Connection>& connection) REQUIRES(mLock);
@@ -697,7 +699,8 @@ private:
DeviceId deviceId) const REQUIRES(mLock);
// Statistics gathering.
- LatencyAggregator mLatencyAggregator GUARDED_BY(mLock);
+ nsecs_t mLastStatisticPushTime = 0;
+ std::unique_ptr<InputEventTimelineProcessor> mInputEventTimelineProcessor GUARDED_BY(mLock);
LatencyTracker mLatencyTracker GUARDED_BY(mLock);
void traceInboundQueueLengthLocked() REQUIRES(mLock);
void traceOutboundQueueLength(const Connection& connection);
diff --git a/services/inputflinger/dispatcher/InputEventTimeline.h b/services/inputflinger/dispatcher/InputEventTimeline.h
index 951fcc8d0c..4552708adc 100644
--- a/services/inputflinger/dispatcher/InputEventTimeline.h
+++ b/services/inputflinger/dispatcher/InputEventTimeline.h
@@ -121,13 +121,21 @@ struct InputEventTimeline {
class InputEventTimelineProcessor {
protected:
InputEventTimelineProcessor() {}
- virtual ~InputEventTimelineProcessor() {}
public:
+ virtual ~InputEventTimelineProcessor() {}
+
/**
* Process the provided timeline
*/
virtual void processTimeline(const InputEventTimeline& timeline) = 0;
+
+ /**
+ * Trigger a push for the input event latency statistics
+ */
+ virtual void pushLatencyStatistics() = 0;
+
+ virtual std::string dump(const char* prefix) const = 0;
};
} // namespace inputdispatcher
diff --git a/services/inputflinger/dispatcher/LatencyAggregator.cpp b/services/inputflinger/dispatcher/LatencyAggregator.cpp
index 4ddd2e9e95..d0e9d7c983 100644
--- a/services/inputflinger/dispatcher/LatencyAggregator.cpp
+++ b/services/inputflinger/dispatcher/LatencyAggregator.cpp
@@ -28,6 +28,8 @@ using android::base::StringPrintf;
using dist_proc::aggregation::KllQuantile;
using std::chrono_literals::operator""ms;
+namespace {
+
// Convert the provided nanoseconds into hundreds of microseconds.
// Use hundreds of microseconds (as opposed to microseconds) to preserve space.
static inline int64_t ns2hus(nsecs_t nanos) {
@@ -74,6 +76,8 @@ static std::chrono::milliseconds getSlowEventMinReportingInterval() {
return std::chrono::milliseconds(std::stoi(millis));
}
+} // namespace
+
namespace android::inputdispatcher {
/**
@@ -125,6 +129,9 @@ void LatencyAggregator::processTimeline(const InputEventTimeline& timeline) {
processSlowEvent(timeline);
}
+// This version of LatencyAggregator doesn't push any atoms
+void LatencyAggregator::pushLatencyStatistics() {}
+
void LatencyAggregator::processStatistics(const InputEventTimeline& timeline) {
std::scoped_lock lock(mLock);
// Before we do any processing, check that we have not yet exceeded MAX_SIZE
diff --git a/services/inputflinger/dispatcher/LatencyAggregator.h b/services/inputflinger/dispatcher/LatencyAggregator.h
index d6d168602a..468add1435 100644
--- a/services/inputflinger/dispatcher/LatencyAggregator.h
+++ b/services/inputflinger/dispatcher/LatencyAggregator.h
@@ -57,6 +57,8 @@ public:
*/
void processTimeline(const InputEventTimeline& timeline) override;
+ void pushLatencyStatistics() override;
+
std::string dump(const char* prefix) const;
~LatencyAggregator();
diff --git a/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.cpp b/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.cpp
new file mode 100644
index 0000000000..881a96b28e
--- /dev/null
+++ b/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.cpp
@@ -0,0 +1,345 @@
+/*
+ * Copyright 2024 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 "LatencyAggregatorWithHistograms"
+#include "../InputDeviceMetricsSource.h"
+#include "InputDispatcher.h"
+
+#include <inttypes.h>
+#include <log/log_event_list.h>
+#include <statslog.h>
+
+#include <android-base/logging.h>
+#include <android-base/stringprintf.h>
+#include <input/Input.h>
+#include <log/log.h>
+#include <server_configurable_flags/get_flags.h>
+
+using android::base::StringPrintf;
+using std::chrono_literals::operator""ms;
+
+namespace {
+
+// Convert the provided nanoseconds into hundreds of microseconds.
+// Use hundreds of microseconds (as opposed to microseconds) to preserve space.
+static inline int64_t ns2hus(nsecs_t nanos) {
+ return ns2us(nanos) / 100;
+}
+
+// Category (=namespace) name for the input settings that are applied at boot time
+static const char* INPUT_NATIVE_BOOT = "input_native_boot";
+// Feature flag name for the threshold of end-to-end touch latency that would trigger
+// SlowEventReported atom to be pushed
+static const char* SLOW_EVENT_MIN_REPORTING_LATENCY_MILLIS =
+ "slow_event_min_reporting_latency_millis";
+// Feature flag name for the minimum delay before reporting a slow event after having just reported
+// a slow event. This helps limit the amount of data sent to the server
+static const char* SLOW_EVENT_MIN_REPORTING_INTERVAL_MILLIS =
+ "slow_event_min_reporting_interval_millis";
+
+// If an event has end-to-end latency > 200 ms, it will get reported as a slow event.
+std::chrono::milliseconds DEFAULT_SLOW_EVENT_MIN_REPORTING_LATENCY = 200ms;
+// If we receive two slow events less than 1 min apart, we will only report 1 of them.
+std::chrono::milliseconds DEFAULT_SLOW_EVENT_MIN_REPORTING_INTERVAL = 60000ms;
+
+static std::chrono::milliseconds getSlowEventMinReportingLatency() {
+ std::string millis = server_configurable_flags::
+ GetServerConfigurableFlag(INPUT_NATIVE_BOOT, SLOW_EVENT_MIN_REPORTING_LATENCY_MILLIS,
+ std::to_string(
+ DEFAULT_SLOW_EVENT_MIN_REPORTING_LATENCY.count()));
+ return std::chrono::milliseconds(std::stoi(millis));
+}
+
+static std::chrono::milliseconds getSlowEventMinReportingInterval() {
+ std::string millis = server_configurable_flags::
+ GetServerConfigurableFlag(INPUT_NATIVE_BOOT, SLOW_EVENT_MIN_REPORTING_INTERVAL_MILLIS,
+ std::to_string(
+ DEFAULT_SLOW_EVENT_MIN_REPORTING_INTERVAL.count()));
+ return std::chrono::milliseconds(std::stoi(millis));
+}
+
+} // namespace
+
+namespace android::inputdispatcher {
+
+int32_t LatencyStageIndexToAtomEnum(LatencyStageIndex latencyStageIndex) {
+ switch (latencyStageIndex) {
+ case LatencyStageIndex::EVENT_TO_READ:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__EVENT_TO_READ;
+ case LatencyStageIndex::READ_TO_DELIVER:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__READ_TO_DELIVER;
+ case LatencyStageIndex::DELIVER_TO_CONSUME:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__DELIVER_TO_CONSUME;
+ case LatencyStageIndex::CONSUME_TO_FINISH:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__CONSUME_TO_FINISH;
+ case LatencyStageIndex::CONSUME_TO_GPU_COMPLETE:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__CONSUME_TO_GPU_COMPLETE;
+ case LatencyStageIndex::GPU_COMPLETE_TO_PRESENT:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__GPU_COMPLETE_TO_PRESENT;
+ case LatencyStageIndex::END_TO_END:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__END_TO_END;
+ default:
+ return util::INPUT_EVENT_LATENCY_REPORTED__LATENCY_STAGE__UNKNOWN_LATENCY_STAGE;
+ }
+}
+
+int32_t InputEventTypeEnumToAtomEnum(InputEventActionType inputEventActionType) {
+ switch (inputEventActionType) {
+ case InputEventActionType::UNKNOWN_INPUT_EVENT:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__UNKNOWN_INPUT_EVENT;
+ case InputEventActionType::MOTION_ACTION_DOWN:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__MOTION_ACTION_DOWN;
+ case InputEventActionType::MOTION_ACTION_MOVE:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__MOTION_ACTION_MOVE;
+ case InputEventActionType::MOTION_ACTION_UP:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__MOTION_ACTION_UP;
+ case InputEventActionType::MOTION_ACTION_HOVER_MOVE:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__MOTION_ACTION_HOVER_MOVE;
+ case InputEventActionType::MOTION_ACTION_SCROLL:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__MOTION_ACTION_SCROLL;
+ case InputEventActionType::KEY:
+ return util::INPUT_EVENT_LATENCY_REPORTED__INPUT_EVENT_TYPE__KEY;
+ }
+}
+
+void LatencyAggregatorWithHistograms::processTimeline(const InputEventTimeline& timeline) {
+ processStatistics(timeline);
+ processSlowEvent(timeline);
+}
+
+void LatencyAggregatorWithHistograms::addSampleToHistogram(
+ const InputEventLatencyIdentifier& identifier, LatencyStageIndex latencyStageIndex,
+ nsecs_t latency) {
+ // Only record positive values for the statistics
+ if (latency > 0) {
+ auto it = mHistograms.find(identifier);
+ if (it != mHistograms.end()) {
+ it->second[static_cast<size_t>(latencyStageIndex)].addSample(ns2hus(latency));
+ }
+ }
+}
+
+void LatencyAggregatorWithHistograms::processStatistics(const InputEventTimeline& timeline) {
+ // Only gather data for Down, Move and Up motion events and Key events
+ if (!(timeline.inputEventActionType == InputEventActionType::MOTION_ACTION_DOWN ||
+ timeline.inputEventActionType == InputEventActionType::MOTION_ACTION_MOVE ||
+ timeline.inputEventActionType == InputEventActionType::MOTION_ACTION_UP ||
+ timeline.inputEventActionType == InputEventActionType::KEY))
+ return;
+
+ // Don't collect data for unidentified devices. This situation can occur for the first few input
+ // events produced when an input device is first connected
+ if (timeline.vendorId == 0xFFFF && timeline.productId == 0xFFFF) return;
+
+ InputEventLatencyIdentifier identifier = {timeline.vendorId, timeline.productId,
+ timeline.sources, timeline.inputEventActionType};
+ // Check if there's a value in mHistograms map associated to identifier.
+ // If not, add an array with 7 empty histograms as an entry
+ if (mHistograms.count(identifier) == 0) {
+ if (static_cast<int32_t>(timeline.inputEventActionType) - 1 < 0) {
+ LOG(FATAL) << "Action index is smaller than 0. Action type: "
+ << ftl::enum_string(timeline.inputEventActionType);
+ return;
+ }
+ size_t actionIndex =
+ static_cast<size_t>(static_cast<int32_t>(timeline.inputEventActionType) - 1);
+ if (actionIndex >= NUM_INPUT_EVENT_TYPES) {
+ LOG(FATAL) << "Action index greater than the number of input event types. Action Type: "
+ << ftl::enum_string(timeline.inputEventActionType)
+ << "; Action Type Index: " << actionIndex;
+ return;
+ }
+
+ std::array<Histogram, 7> histograms =
+ {Histogram(allBinSizes[binSizesMappings[0][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[1][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[2][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[3][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[4][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[5][actionIndex]]),
+ Histogram(allBinSizes[binSizesMappings[6][actionIndex]])};
+ mHistograms.insert({identifier, histograms});
+ }
+
+ // Process common ones first
+ const nsecs_t eventToRead = timeline.readTime - timeline.eventTime;
+ addSampleToHistogram(identifier, LatencyStageIndex::EVENT_TO_READ, eventToRead);
+
+ // Now process per-connection ones
+ for (const auto& [connectionToken, connectionTimeline] : timeline.connectionTimelines) {
+ if (!connectionTimeline.isComplete()) {
+ continue;
+ }
+ const nsecs_t readToDeliver = connectionTimeline.deliveryTime - timeline.readTime;
+ const nsecs_t deliverToConsume =
+ connectionTimeline.consumeTime - connectionTimeline.deliveryTime;
+ const nsecs_t consumeToFinish =
+ connectionTimeline.finishTime - connectionTimeline.consumeTime;
+ const nsecs_t gpuCompletedTime =
+ connectionTimeline.graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME];
+ const nsecs_t presentTime =
+ connectionTimeline.graphicsTimeline[GraphicsTimeline::PRESENT_TIME];
+ const nsecs_t consumeToGpuComplete = gpuCompletedTime - connectionTimeline.consumeTime;
+ const nsecs_t gpuCompleteToPresent = presentTime - gpuCompletedTime;
+ const nsecs_t endToEnd = presentTime - timeline.eventTime;
+
+ addSampleToHistogram(identifier, LatencyStageIndex::READ_TO_DELIVER, readToDeliver);
+ addSampleToHistogram(identifier, LatencyStageIndex::DELIVER_TO_CONSUME, deliverToConsume);
+ addSampleToHistogram(identifier, LatencyStageIndex::CONSUME_TO_FINISH, consumeToFinish);
+ addSampleToHistogram(identifier, LatencyStageIndex::CONSUME_TO_GPU_COMPLETE,
+ consumeToGpuComplete);
+ addSampleToHistogram(identifier, LatencyStageIndex::GPU_COMPLETE_TO_PRESENT,
+ gpuCompleteToPresent);
+ addSampleToHistogram(identifier, LatencyStageIndex::END_TO_END, endToEnd);
+ }
+}
+
+void LatencyAggregatorWithHistograms::pushLatencyStatistics() {
+ for (auto& [id, histograms] : mHistograms) {
+ auto [vendorId, productId, sources, action] = id;
+ for (size_t latencyStageIndex = static_cast<size_t>(LatencyStageIndex::EVENT_TO_READ);
+ latencyStageIndex < static_cast<size_t>(LatencyStageIndex::SIZE);
+ ++latencyStageIndex) {
+ // Convert sources set to vector for atom logging:
+ std::vector<int32_t> sourcesVector = {};
+ for (auto& elem : sources) {
+ sourcesVector.push_back(static_cast<int32_t>(elem));
+ }
+
+ // convert histogram bin counts array to vector for atom logging:
+ std::array arr = histograms[latencyStageIndex].getBinCounts();
+ std::vector<int32_t> binCountsVector(arr.begin(), arr.end());
+
+ if (static_cast<int32_t>(action) - 1 < 0) {
+ ALOGW("Action index is smaller than 0. Action type: %s",
+ ftl::enum_string(action).c_str());
+ continue;
+ }
+ size_t actionIndex = static_cast<size_t>(static_cast<int32_t>(action) - 1);
+ if (actionIndex >= NUM_INPUT_EVENT_TYPES) {
+ ALOGW("Action index greater than the number of input event types. Action Type: %s; "
+ "Action Type Index: %zu",
+ ftl::enum_string(action).c_str(), actionIndex);
+ continue;
+ }
+
+ stats_write(android::util::INPUT_EVENT_LATENCY_REPORTED, vendorId, productId,
+ sourcesVector, InputEventTypeEnumToAtomEnum(action),
+ LatencyStageIndexToAtomEnum(
+ static_cast<LatencyStageIndex>(latencyStageIndex)),
+ histogramVersions[latencyStageIndex][actionIndex], binCountsVector);
+ }
+ }
+ mHistograms.clear();
+}
+
+// TODO (b/270049345): For now, we just copied the code from LatencyAggregator to populate the old
+// atom, but eventually we should migrate this to use the new SlowEventReported atom
+void LatencyAggregatorWithHistograms::processSlowEvent(const InputEventTimeline& timeline) {
+ static const std::chrono::duration sSlowEventThreshold = getSlowEventMinReportingLatency();
+ static const std::chrono::duration sSlowEventReportingInterval =
+ getSlowEventMinReportingInterval();
+ for (const auto& [token, connectionTimeline] : timeline.connectionTimelines) {
+ if (!connectionTimeline.isComplete()) {
+ continue;
+ }
+ mNumEventsSinceLastSlowEventReport++;
+ const nsecs_t presentTime =
+ connectionTimeline.graphicsTimeline[GraphicsTimeline::PRESENT_TIME];
+ const std::chrono::nanoseconds endToEndLatency =
+ std::chrono::nanoseconds(presentTime - timeline.eventTime);
+ if (endToEndLatency < sSlowEventThreshold) {
+ continue;
+ }
+ // This is a slow event. Before we report it, check if we are reporting too often
+ const std::chrono::duration elapsedSinceLastReport =
+ std::chrono::nanoseconds(timeline.eventTime - mLastSlowEventTime);
+ if (elapsedSinceLastReport < sSlowEventReportingInterval) {
+ mNumSkippedSlowEvents++;
+ continue;
+ }
+
+ const nsecs_t eventToRead = timeline.readTime - timeline.eventTime;
+ const nsecs_t readToDeliver = connectionTimeline.deliveryTime - timeline.readTime;
+ const nsecs_t deliverToConsume =
+ connectionTimeline.consumeTime - connectionTimeline.deliveryTime;
+ const nsecs_t consumeToFinish =
+ connectionTimeline.finishTime - connectionTimeline.consumeTime;
+ const nsecs_t gpuCompletedTime =
+ connectionTimeline.graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME];
+ const nsecs_t consumeToGpuComplete = gpuCompletedTime - connectionTimeline.consumeTime;
+ const nsecs_t gpuCompleteToPresent = presentTime - gpuCompletedTime;
+
+ android::util::stats_write(android::util::SLOW_INPUT_EVENT_REPORTED,
+ timeline.inputEventActionType ==
+ InputEventActionType::MOTION_ACTION_DOWN,
+ static_cast<int32_t>(ns2us(eventToRead)),
+ static_cast<int32_t>(ns2us(readToDeliver)),
+ static_cast<int32_t>(ns2us(deliverToConsume)),
+ static_cast<int32_t>(ns2us(consumeToFinish)),
+ static_cast<int32_t>(ns2us(consumeToGpuComplete)),
+ static_cast<int32_t>(ns2us(gpuCompleteToPresent)),
+ static_cast<int32_t>(ns2us(endToEndLatency.count())),
+ static_cast<int32_t>(mNumEventsSinceLastSlowEventReport),
+ static_cast<int32_t>(mNumSkippedSlowEvents));
+ mNumEventsSinceLastSlowEventReport = 0;
+ mNumSkippedSlowEvents = 0;
+ mLastSlowEventTime = timeline.readTime;
+ }
+}
+
+std::string LatencyAggregatorWithHistograms::dump(const char* prefix) const {
+ std::string statisticsStr = StringPrintf("%s Histograms:\n", prefix);
+ for (const auto& [id, histograms] : mHistograms) {
+ auto [vendorId, productId, sources, action] = id;
+
+ std::string identifierStr =
+ StringPrintf("%s Identifier: vendor %d, product %d, sources: {", prefix, vendorId,
+ productId);
+ bool firstSource = true;
+ for (const auto& source : sources) {
+ if (!firstSource) {
+ identifierStr += ", ";
+ }
+ identifierStr += StringPrintf("%d", static_cast<int32_t>(source));
+ firstSource = false;
+ }
+ identifierStr += StringPrintf("}, action: %d\n", static_cast<int32_t>(action));
+
+ std::string histogramsStr;
+ for (size_t stageIndex = 0; stageIndex < static_cast<size_t>(LatencyStageIndex::SIZE);
+ stageIndex++) {
+ const auto& histogram = histograms[stageIndex];
+ const std::array<int, NUM_BINS>& binCounts = histogram.getBinCounts();
+
+ histogramsStr += StringPrintf("%s %zu: ", prefix, stageIndex);
+ histogramsStr += StringPrintf("%d", binCounts[0]);
+ for (size_t bin = 1; bin < NUM_BINS; bin++) {
+ histogramsStr += StringPrintf(", %d", binCounts[bin]);
+ }
+ histogramsStr += StringPrintf("\n");
+ }
+ statisticsStr += identifierStr + histogramsStr;
+ }
+
+ return StringPrintf("%sLatencyAggregatorWithHistograms:\n", prefix) + statisticsStr +
+ StringPrintf("%s mLastSlowEventTime=%" PRId64 "\n", prefix, mLastSlowEventTime) +
+ StringPrintf("%s mNumEventsSinceLastSlowEventReport = %zu\n", prefix,
+ mNumEventsSinceLastSlowEventReport) +
+ StringPrintf("%s mNumSkippedSlowEvents = %zu\n", prefix, mNumSkippedSlowEvents);
+}
+
+} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.h b/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.h
new file mode 100644
index 0000000000..2ceb0e7cb7
--- /dev/null
+++ b/services/inputflinger/dispatcher/LatencyAggregatorWithHistograms.h
@@ -0,0 +1,164 @@
+/*
+ * Copyright 2024 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.
+ */
+
+#pragma once
+
+#include <android-base/thread_annotations.h>
+#include <utils/Timers.h>
+
+#include "InputEventTimeline.h"
+
+namespace android::inputdispatcher {
+
+static constexpr size_t NUM_BINS = 20;
+static constexpr size_t NUM_INPUT_EVENT_TYPES = 6;
+
+enum class LatencyStageIndex : size_t {
+ EVENT_TO_READ = 0,
+ READ_TO_DELIVER = 1,
+ DELIVER_TO_CONSUME = 2,
+ CONSUME_TO_FINISH = 3,
+ CONSUME_TO_GPU_COMPLETE = 4,
+ GPU_COMPLETE_TO_PRESENT = 5,
+ END_TO_END = 6,
+ SIZE = 7, // must be last
+};
+
+// Let's create a full timeline here:
+// eventTime
+// readTime
+// <---- after this point, the data becomes per-connection
+// deliveryTime // time at which the event was sent to the receiver
+// consumeTime // time at which the receiver read the event
+// finishTime // time at which the dispatcher reads the response from the receiver that the event
+// was processed
+// GraphicsTimeline::GPU_COMPLETED_TIME
+// GraphicsTimeline::PRESENT_TIME
+
+/**
+ * Keep histograms with latencies of the provided events
+ */
+class LatencyAggregatorWithHistograms final : public InputEventTimelineProcessor {
+public:
+ /**
+ * Record a complete event timeline
+ */
+ void processTimeline(const InputEventTimeline& timeline) override;
+
+ void pushLatencyStatistics() override;
+
+ std::string dump(const char* prefix) const override;
+
+private:
+ // ---------- Slow event handling ----------
+ void processSlowEvent(const InputEventTimeline& timeline);
+ nsecs_t mLastSlowEventTime = 0;
+ // How many slow events have been skipped due to rate limiting
+ size_t mNumSkippedSlowEvents = 0;
+ // How many events have been received since the last time we reported a slow event
+ size_t mNumEventsSinceLastSlowEventReport = 0;
+
+ // ---------- Statistics handling ----------
+ /**
+ * Data structure to gather time samples into NUM_BINS buckets
+ */
+ class Histogram {
+ public:
+ Histogram(const std::array<int, NUM_BINS - 1>& binSizes) : mBinSizes(binSizes) {
+ mBinCounts.fill(0);
+ }
+
+ // Increments binCounts of the appropriate bin when adding a new sample
+ void addSample(int64_t sample) {
+ size_t binIndex = getSampleBinIndex(sample);
+ mBinCounts[binIndex]++;
+ }
+
+ const std::array<int32_t, NUM_BINS>& getBinCounts() const { return mBinCounts; }
+
+ private:
+ // reference to an array that represents the range of values each bin holds.
+ // in bin i+1 live samples such that *mBinSizes[i] <= sample < *mBinSizes[i+1]
+ const std::array<int, NUM_BINS - 1>& mBinSizes;
+ std::array<int32_t, NUM_BINS>
+ mBinCounts; // the number of samples that currently live in each bin
+
+ size_t getSampleBinIndex(int64_t sample) {
+ auto it = std::upper_bound(mBinSizes.begin(), mBinSizes.end(), sample);
+ return std::distance(mBinSizes.begin(), it);
+ }
+ };
+
+ void processStatistics(const InputEventTimeline& timeline);
+
+ // Identifier for the an input event. If two input events have the same identifiers we
+ // want to use the same histograms to count the latency samples
+ using InputEventLatencyIdentifier =
+ std::tuple<uint16_t /*vendorId*/, uint16_t /*productId*/,
+ const std::set<InputDeviceUsageSource> /*sources*/,
+ InputEventActionType /*inputEventActionType*/>;
+
+ // Maps an input event identifier to an array of 7 histograms, one for each latency
+ // stage. It is cleared after an atom push
+ std::map<InputEventLatencyIdentifier, std::array<Histogram, 7>> mHistograms;
+
+ void addSampleToHistogram(const InputEventLatencyIdentifier& identifier,
+ LatencyStageIndex latencyStageIndex, nsecs_t time);
+
+ // Stores all possible arrays of bin sizes. The order in the vector does not matter, as long
+ // as binSizesMappings points to the right index
+ static constexpr std::array<std::array<int, NUM_BINS - 1>, 6> allBinSizes = {
+ {{10, 15, 20, 25, 30, 35, 40, 45, 50, 55, 60, 65, 70, 75, 80, 85, 90, 95, 100},
+ {1, 2, 3, 4, 5, 6, 8, 10, 12, 14, 16, 18, 20, 22, 24, 26, 28, 30, 32},
+ {15, 30, 45, 60, 75, 90, 105, 120, 135, 150, 165, 180, 195, 210, 225, 240, 255, 270,
+ 285},
+ {40, 80, 120, 160, 200, 240, 280, 320, 360, 400, 440, 480, 520, 560, 600, 640, 680,
+ 720, 760},
+ {20, 40, 60, 80, 100, 120, 140, 160, 180, 200, 220, 240, 260, 280, 300, 320, 340, 360,
+ 380},
+ {200, 300, 400, 500, 600, 700, 800, 900, 1000, 1100, 1200, 1300, 1400, 1500, 1600,
+ 1700, 1800, 1900, 2000}}};
+
+ // Stores indexes in allBinSizes to use with each {LatencyStage, InputEventType} pair.
+ // Bin sizes for a certain latencyStage and inputEventType are at:
+ // *(allBinSizes[binSizesMappings[latencyStageIndex][inputEventTypeIndex]])
+ // inputEventTypeIndex is the int value of InputEventActionType enum decreased by 1 since we
+ // don't want to record latencies for unknown events.
+ // e.g. MOTION_ACTION_DOWN is 0, MOTION_ACTION_MOVE is 1...
+ static constexpr std::array<std::array<int8_t, NUM_INPUT_EVENT_TYPES>,
+ static_cast<size_t>(LatencyStageIndex::SIZE)>
+ binSizesMappings = {{{0, 0, 0, 0, 0, 0},
+ {1, 1, 1, 1, 1, 1},
+ {1, 1, 1, 1, 1, 1},
+ {2, 2, 2, 2, 2, 2},
+ {3, 3, 3, 3, 3, 3},
+ {4, 4, 4, 4, 4, 4},
+ {5, 5, 5, 5, 5, 5}}};
+
+ // Similar to binSizesMappings, but holds the index of the array of bin ranges to use on the
+ // server. The index gets pushed with the atom within the histogram_version field.
+ static constexpr std::array<std::array<int8_t, NUM_INPUT_EVENT_TYPES>,
+ static_cast<size_t>(LatencyStageIndex::SIZE)>
+ histogramVersions = {{{0, 0, 0, 0, 0, 0},
+ {1, 1, 1, 1, 1, 1},
+ {1, 1, 1, 1, 1, 1},
+ {2, 2, 2, 2, 2, 2},
+ {3, 3, 3, 3, 3, 3},
+ {4, 4, 4, 4, 4, 4},
+ {5, 5, 5, 5, 5, 5}}};
+};
+
+} // namespace android::inputdispatcher
diff --git a/services/inputflinger/dispatcher/LatencyTracker.cpp b/services/inputflinger/dispatcher/LatencyTracker.cpp
index 69024b326a..d203fbabf6 100644
--- a/services/inputflinger/dispatcher/LatencyTracker.cpp
+++ b/services/inputflinger/dispatcher/LatencyTracker.cpp
@@ -62,10 +62,8 @@ static void eraseByValue(std::multimap<K, V>& map, const V& value) {
}
}
-LatencyTracker::LatencyTracker(InputEventTimelineProcessor* processor)
- : mTimelineProcessor(processor) {
- LOG_ALWAYS_FATAL_IF(processor == nullptr);
-}
+LatencyTracker::LatencyTracker(InputEventTimelineProcessor& processor)
+ : mTimelineProcessor(&processor) {}
void LatencyTracker::trackListener(int32_t inputEventId, nsecs_t eventTime, nsecs_t readTime,
DeviceId deviceId,
diff --git a/services/inputflinger/dispatcher/LatencyTracker.h b/services/inputflinger/dispatcher/LatencyTracker.h
index b4053ba1b3..80d3f2f294 100644
--- a/services/inputflinger/dispatcher/LatencyTracker.h
+++ b/services/inputflinger/dispatcher/LatencyTracker.h
@@ -42,7 +42,7 @@ public:
* Create a LatencyTracker.
* param reportingFunction: the function that will be called in order to report full latency.
*/
- LatencyTracker(InputEventTimelineProcessor* processor);
+ LatencyTracker(InputEventTimelineProcessor& processor);
/**
* Start keeping track of an event identified by inputEventId. This must be called first.
* If duplicate events are encountered (events that have the same eventId), none of them will be
diff --git a/services/inputflinger/tests/LatencyTracker_test.cpp b/services/inputflinger/tests/LatencyTracker_test.cpp
index 0f92833e64..3f14c2312b 100644
--- a/services/inputflinger/tests/LatencyTracker_test.cpp
+++ b/services/inputflinger/tests/LatencyTracker_test.cpp
@@ -87,7 +87,7 @@ protected:
connection1 = sp<BBinder>::make();
connection2 = sp<BBinder>::make();
- mTracker = std::make_unique<LatencyTracker>(this);
+ mTracker = std::make_unique<LatencyTracker>(*this);
setDefaultInputDeviceInfo(*mTracker);
}
void TearDown() override {}
@@ -106,6 +106,8 @@ private:
void processTimeline(const InputEventTimeline& timeline) override {
mReceivedTimelines.push_back(timeline);
}
+ void pushLatencyStatistics() override {}
+ std::string dump(const char* prefix) const { return ""; };
std::deque<InputEventTimeline> mReceivedTimelines;
};
diff --git a/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp b/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp
index 695eb3c5dd..908fa40f05 100644
--- a/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp
+++ b/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp
@@ -38,6 +38,10 @@ public:
connectionTimeline.isComplete();
}
};
+
+ void pushLatencyStatistics() override {}
+
+ std::string dump(const char* prefix) const { return ""; };
};
static sp<IBinder> getConnectionToken(FuzzedDataProvider& fdp,
@@ -53,7 +57,7 @@ extern "C" int LLVMFuzzerTestOneInput(uint8_t* data, size_t size) {
FuzzedDataProvider fdp(data, size);
EmptyProcessor emptyProcessor;
- LatencyTracker tracker(&emptyProcessor);
+ LatencyTracker tracker(emptyProcessor);
// Make some pre-defined tokens to ensure that some timelines are complete.
std::array<sp<IBinder> /*token*/, 10> predefinedTokens;