blob: 0852026823d934f5fe97a83de76e715b87ae8a45 [file] [log] [blame]
Siarhei Vishniakouf2652122021-03-05 21:39:46 +00001/*
2 * Copyright (C) 2021 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#define LOG_TAG "LatencyTracker"
18#include "LatencyTracker.h"
Asmita Poddardd9a6cd2023-09-26 15:35:12 +000019#include "../InputDeviceMetricsSource.h"
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000020
21#include <inttypes.h>
22
23#include <android-base/properties.h>
24#include <android-base/stringprintf.h>
25#include <android/os/IInputConstants.h>
26#include <input/Input.h>
Asmita Poddardd9a6cd2023-09-26 15:35:12 +000027#include <input/InputDevice.h>
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000028#include <log/log.h>
29
30using android::base::HwTimeoutMultiplier;
31using android::base::StringPrintf;
32
33namespace android::inputdispatcher {
34
35/**
36 * Events that are older than this time will be considered mature, at which point we will stop
37 * waiting for the apps to provide further information about them.
38 * It's likely that the apps will ANR if the events are not received by this deadline, and we
39 * already track ANR metrics separately.
40 */
41const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds(
42 android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS *
43 HwTimeoutMultiplier());
44
45static bool isMatureEvent(nsecs_t eventTime, nsecs_t now) {
46 std::chrono::duration age = std::chrono::nanoseconds(now) - std::chrono::nanoseconds(eventTime);
47 return age > ANR_TIMEOUT;
48}
49
50/**
51 * A multimap allows to have several entries with the same key. This function just erases a specific
52 * key-value pair. Equivalent to the imaginary std api std::multimap::erase(key, value).
53 */
54template <typename K, typename V>
Siarhei Vishniakou363e7292021-07-09 03:22:42 +000055static void eraseByValue(std::multimap<K, V>& map, const V& value) {
56 for (auto it = map.begin(); it != map.end();) {
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000057 if (it->second == value) {
Siarhei Vishniakou363e7292021-07-09 03:22:42 +000058 it = map.erase(it);
59 } else {
60 it++;
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000061 }
62 }
63}
64
jioana24878b52024-09-10 10:13:27 +000065LatencyTracker::LatencyTracker(InputEventTimelineProcessor& processor)
66 : mTimelineProcessor(&processor) {}
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000067
jioana099e19a2024-09-19 15:37:34 +000068void LatencyTracker::trackNotifyMotion(const NotifyMotionArgs& args) {
69 std::set<InputDeviceUsageSource> sources = getUsageSourcesForMotionArgs(args);
70 trackListener(args.id, args.eventTime, args.readTime, args.deviceId, sources, args.action,
71 InputEventType::MOTION);
72}
73
74void LatencyTracker::trackNotifyKey(const NotifyKeyArgs& args) {
75 int32_t keyboardType = AINPUT_KEYBOARD_TYPE_NONE;
76 for (auto& inputDevice : mInputDevices) {
77 if (args.deviceId == inputDevice.getId()) {
78 keyboardType = inputDevice.getKeyboardType();
79 break;
80 }
81 }
82 std::set<InputDeviceUsageSource> sources =
83 std::set{getUsageSourceForKeyArgs(keyboardType, args)};
84 trackListener(args.id, args.eventTime, args.readTime, args.deviceId, sources, args.action,
85 InputEventType::KEY);
86}
87
jioana0bdbea12024-08-10 19:26:04 +000088void LatencyTracker::trackListener(int32_t inputEventId, nsecs_t eventTime, nsecs_t readTime,
89 DeviceId deviceId,
90 const std::set<InputDeviceUsageSource>& sources,
jioana97cc8ac2024-09-09 15:01:43 +000091 int32_t inputEventAction, InputEventType inputEventType) {
Siarhei Vishniakouf2652122021-03-05 21:39:46 +000092 reportAndPruneMatureRecords(eventTime);
93 const auto it = mTimelines.find(inputEventId);
94 if (it != mTimelines.end()) {
95 // Input event ids are randomly generated, so it's possible that two events have the same
96 // event id. Drop this event, and also drop the existing event because the apps would
97 // confuse us by reporting the rest of the timeline for one of them. This should happen
98 // rarely, so we won't lose much data
99 mTimelines.erase(it);
Siarhei Vishniakou363e7292021-07-09 03:22:42 +0000100 eraseByValue(mEventTimes, inputEventId);
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000101 return;
102 }
Asmita Poddardd9a6cd2023-09-26 15:35:12 +0000103
104 // Create an InputEventTimeline for the device ID. The vendorId and productId
105 // can be obtained from the InputDeviceIdentifier of the particular device.
106 const InputDeviceIdentifier* identifier = nullptr;
107 for (auto& inputDevice : mInputDevices) {
108 if (deviceId == inputDevice.getId()) {
109 identifier = &inputDevice.getIdentifier();
110 break;
111 }
112 }
113
114 // If no matching ids can be found for the device from among the input devices connected,
115 // the call to trackListener will be dropped.
116 // Note: there generally isn't expected to be a situation where we can't find an InputDeviceInfo
117 // but a possibility of it is handled in case of race conditions
118 if (identifier == nullptr) {
119 ALOGE("Could not find input device identifier. Dropping call to LatencyTracker.");
120 return;
121 }
122
jioana0bdbea12024-08-10 19:26:04 +0000123 const InputEventActionType inputEventActionType = [&]() {
124 switch (inputEventType) {
125 case InputEventType::MOTION: {
jioana97cc8ac2024-09-09 15:01:43 +0000126 switch (MotionEvent::getActionMasked(inputEventAction)) {
jioana0bdbea12024-08-10 19:26:04 +0000127 case AMOTION_EVENT_ACTION_DOWN:
128 return InputEventActionType::MOTION_ACTION_DOWN;
129 case AMOTION_EVENT_ACTION_MOVE:
130 return InputEventActionType::MOTION_ACTION_MOVE;
131 case AMOTION_EVENT_ACTION_UP:
132 return InputEventActionType::MOTION_ACTION_UP;
133 case AMOTION_EVENT_ACTION_HOVER_MOVE:
134 return InputEventActionType::MOTION_ACTION_HOVER_MOVE;
135 case AMOTION_EVENT_ACTION_SCROLL:
136 return InputEventActionType::MOTION_ACTION_SCROLL;
137 default:
138 return InputEventActionType::UNKNOWN_INPUT_EVENT;
139 }
140 }
141 case InputEventType::KEY: {
142 switch (inputEventAction) {
143 case AKEY_EVENT_ACTION_DOWN:
144 case AKEY_EVENT_ACTION_UP:
145 return InputEventActionType::KEY;
146 default:
147 return InputEventActionType::UNKNOWN_INPUT_EVENT;
148 }
149 }
150 default:
151 return InputEventActionType::UNKNOWN_INPUT_EVENT;
152 }
153 }();
154
Asmita Poddardd9a6cd2023-09-26 15:35:12 +0000155 mTimelines.emplace(inputEventId,
jioana97cc8ac2024-09-09 15:01:43 +0000156 InputEventTimeline(eventTime, readTime, identifier->vendor,
jioana0bdbea12024-08-10 19:26:04 +0000157 identifier->product, sources, inputEventActionType));
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000158 mEventTimes.emplace(eventTime, inputEventId);
159}
160
161void LatencyTracker::trackFinishedEvent(int32_t inputEventId, const sp<IBinder>& connectionToken,
162 nsecs_t deliveryTime, nsecs_t consumeTime,
163 nsecs_t finishTime) {
164 const auto it = mTimelines.find(inputEventId);
165 if (it == mTimelines.end()) {
Siarhei Vishniakou363e7292021-07-09 03:22:42 +0000166 // This could happen if we erased this event when duplicate events were detected. It's
167 // also possible that an app sent a bad (or late) 'Finish' signal, since it's free to do
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000168 // anything in its process. Just drop the report and move on.
169 return;
170 }
171
172 InputEventTimeline& timeline = it->second;
173 const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
174 if (connectionIt == timeline.connectionTimelines.end()) {
175 // Most likely case: app calls 'finishInputEvent' before it reports the graphics timeline
176 timeline.connectionTimelines.emplace(connectionToken,
177 ConnectionTimeline{deliveryTime, consumeTime,
178 finishTime});
179 } else {
180 // Already have a record for this connectionToken
181 ConnectionTimeline& connectionTimeline = connectionIt->second;
182 const bool success =
183 connectionTimeline.setDispatchTimeline(deliveryTime, consumeTime, finishTime);
184 if (!success) {
185 // We are receiving unreliable data from the app. Just delete the entire connection
186 // timeline for this event
187 timeline.connectionTimelines.erase(connectionIt);
188 }
189 }
190}
191
192void LatencyTracker::trackGraphicsLatency(
193 int32_t inputEventId, const sp<IBinder>& connectionToken,
194 std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline) {
195 const auto it = mTimelines.find(inputEventId);
196 if (it == mTimelines.end()) {
Siarhei Vishniakou363e7292021-07-09 03:22:42 +0000197 // This could happen if we erased this event when duplicate events were detected. It's
198 // also possible that an app sent a bad (or late) 'Timeline' signal, since it's free to do
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000199 // anything in its process. Just drop the report and move on.
200 return;
201 }
202
203 InputEventTimeline& timeline = it->second;
204 const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
205 if (connectionIt == timeline.connectionTimelines.end()) {
206 timeline.connectionTimelines.emplace(connectionToken, std::move(graphicsTimeline));
207 } else {
208 // Most likely case
209 ConnectionTimeline& connectionTimeline = connectionIt->second;
210 const bool success = connectionTimeline.setGraphicsTimeline(std::move(graphicsTimeline));
211 if (!success) {
212 // We are receiving unreliable data from the app. Just delete the entire connection
213 // timeline for this event
214 timeline.connectionTimelines.erase(connectionIt);
215 }
216 }
217}
218
219/**
220 * We should use the current time 'now()' here to determine the age of the event, but instead we
221 * are using the latest 'eventTime' for efficiency since this time is already acquired, and
222 * 'trackListener' should happen soon after the event occurs.
223 */
224void LatencyTracker::reportAndPruneMatureRecords(nsecs_t newEventTime) {
225 while (!mEventTimes.empty()) {
226 const auto& [oldestEventTime, oldestInputEventId] = *mEventTimes.begin();
Harry Cutts33476232023-01-30 19:57:29 +0000227 if (isMatureEvent(oldestEventTime, /*now=*/newEventTime)) {
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000228 // Report and drop this event
229 const auto it = mTimelines.find(oldestInputEventId);
230 LOG_ALWAYS_FATAL_IF(it == mTimelines.end(),
231 "Event %" PRId32 " is in mEventTimes, but not in mTimelines",
232 oldestInputEventId);
233 const InputEventTimeline& timeline = it->second;
234 mTimelineProcessor->processTimeline(timeline);
235 mTimelines.erase(it);
236 mEventTimes.erase(mEventTimes.begin());
237 } else {
238 // If the oldest event does not need to be pruned, no events should be pruned.
239 return;
240 }
241 }
242}
243
Siarhei Vishniakou4c9d6ff2023-04-18 11:23:20 -0700244std::string LatencyTracker::dump(const char* prefix) const {
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000245 return StringPrintf("%sLatencyTracker:\n", prefix) +
246 StringPrintf("%s mTimelines.size() = %zu\n", prefix, mTimelines.size()) +
247 StringPrintf("%s mEventTimes.size() = %zu\n", prefix, mEventTimes.size());
248}
249
Asmita Poddardd9a6cd2023-09-26 15:35:12 +0000250void LatencyTracker::setInputDevices(const std::vector<InputDeviceInfo>& inputDevices) {
251 mInputDevices = inputDevices;
252}
253
Siarhei Vishniakouf2652122021-03-05 21:39:46 +0000254} // namespace android::inputdispatcher