Merge "LatencyAggregatorWithHistograms for InputEventLatencyReported atom." into main
diff --git a/services/inputflinger/dispatcher/Android.bp b/services/inputflinger/dispatcher/Android.bp
index 1a0ec48..8b2b843 100644
--- a/services/inputflinger/dispatcher/Android.bp
+++ b/services/inputflinger/dispatcher/Android.bp
@@ -46,6 +46,7 @@
"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 05139cf..9cf9487 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -155,6 +155,10 @@
// 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;
@@ -947,8 +951,13 @@
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();
@@ -1020,6 +1029,11 @@
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) {
@@ -1100,6 +1114,21 @@
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) {
@@ -6089,7 +6118,7 @@
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 1904058..d90b9de 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 @@
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 @@
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 951fcc8..4552708 100644
--- a/services/inputflinger/dispatcher/InputEventTimeline.h
+++ b/services/inputflinger/dispatcher/InputEventTimeline.h
@@ -121,13 +121,21 @@
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 4ddd2e9..d0e9d7c 100644
--- a/services/inputflinger/dispatcher/LatencyAggregator.cpp
+++ b/services/inputflinger/dispatcher/LatencyAggregator.cpp
@@ -28,6 +28,8 @@
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 @@
return std::chrono::milliseconds(std::stoi(millis));
}
+} // namespace
+
namespace android::inputdispatcher {
/**
@@ -125,6 +129,9 @@
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 d6d1686..468add1 100644
--- a/services/inputflinger/dispatcher/LatencyAggregator.h
+++ b/services/inputflinger/dispatcher/LatencyAggregator.h
@@ -57,6 +57,8 @@
*/
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 0000000..881a96b
--- /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 0000000..2ceb0e7
--- /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 69024b3..d203fba 100644
--- a/services/inputflinger/dispatcher/LatencyTracker.cpp
+++ b/services/inputflinger/dispatcher/LatencyTracker.cpp
@@ -62,10 +62,8 @@
}
}
-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 b4053ba..80d3f2f 100644
--- a/services/inputflinger/dispatcher/LatencyTracker.h
+++ b/services/inputflinger/dispatcher/LatencyTracker.h
@@ -42,7 +42,7 @@
* 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 0f92833..3f14c23 100644
--- a/services/inputflinger/tests/LatencyTracker_test.cpp
+++ b/services/inputflinger/tests/LatencyTracker_test.cpp
@@ -87,7 +87,7 @@
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 @@
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 695eb3c..908fa40 100644
--- a/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp
+++ b/services/inputflinger/tests/fuzzers/LatencyTrackerFuzzer.cpp
@@ -38,6 +38,10 @@
connectionTimeline.isComplete();
}
};
+
+ void pushLatencyStatistics() override {}
+
+ std::string dump(const char* prefix) const { return ""; };
};
static sp<IBinder> getConnectionToken(FuzzedDataProvider& fdp,
@@ -53,7 +57,7 @@
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;