1 /*
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"
19 #include "../InputDeviceMetricsSource.h"
20
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>
27 #include <input/InputDevice.h>
28 #include <log/log.h>
29
30 using android::base::HwTimeoutMultiplier;
31 using android::base::StringPrintf;
32
33 namespace 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 */
41 const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds(
42 android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS *
43 HwTimeoutMultiplier());
44
isMatureEvent(nsecs_t eventTime,nsecs_t now)45 static 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 */
54 template <typename K, typename V>
eraseByValue(std::multimap<K,V> & map,const V & value)55 static void eraseByValue(std::multimap<K, V>& map, const V& value) {
56 for (auto it = map.begin(); it != map.end();) {
57 if (it->second == value) {
58 it = map.erase(it);
59 } else {
60 it++;
61 }
62 }
63 }
64
LatencyTracker(InputEventTimelineProcessor * processor)65 LatencyTracker::LatencyTracker(InputEventTimelineProcessor* processor)
66 : mTimelineProcessor(processor) {
67 LOG_ALWAYS_FATAL_IF(processor == nullptr);
68 }
69
trackListener(int32_t inputEventId,bool isDown,nsecs_t eventTime,nsecs_t readTime,DeviceId deviceId,const std::set<InputDeviceUsageSource> & sources)70 void LatencyTracker::trackListener(int32_t inputEventId, bool isDown, nsecs_t eventTime,
71 nsecs_t readTime, DeviceId deviceId,
72 const std::set<InputDeviceUsageSource>& sources) {
73 reportAndPruneMatureRecords(eventTime);
74 const auto it = mTimelines.find(inputEventId);
75 if (it != mTimelines.end()) {
76 // Input event ids are randomly generated, so it's possible that two events have the same
77 // event id. Drop this event, and also drop the existing event because the apps would
78 // confuse us by reporting the rest of the timeline for one of them. This should happen
79 // rarely, so we won't lose much data
80 mTimelines.erase(it);
81 eraseByValue(mEventTimes, inputEventId);
82 return;
83 }
84
85 // Create an InputEventTimeline for the device ID. The vendorId and productId
86 // can be obtained from the InputDeviceIdentifier of the particular device.
87 const InputDeviceIdentifier* identifier = nullptr;
88 for (auto& inputDevice : mInputDevices) {
89 if (deviceId == inputDevice.getId()) {
90 identifier = &inputDevice.getIdentifier();
91 break;
92 }
93 }
94
95 // If no matching ids can be found for the device from among the input devices connected,
96 // the call to trackListener will be dropped.
97 // Note: there generally isn't expected to be a situation where we can't find an InputDeviceInfo
98 // but a possibility of it is handled in case of race conditions
99 if (identifier == nullptr) {
100 ALOGE("Could not find input device identifier. Dropping call to LatencyTracker.");
101 return;
102 }
103
104 mTimelines.emplace(inputEventId,
105 InputEventTimeline(isDown, eventTime, readTime, identifier->vendor,
106 identifier->product, sources));
107 mEventTimes.emplace(eventTime, inputEventId);
108 }
109
trackFinishedEvent(int32_t inputEventId,const sp<IBinder> & connectionToken,nsecs_t deliveryTime,nsecs_t consumeTime,nsecs_t finishTime)110 void LatencyTracker::trackFinishedEvent(int32_t inputEventId, const sp<IBinder>& connectionToken,
111 nsecs_t deliveryTime, nsecs_t consumeTime,
112 nsecs_t finishTime) {
113 const auto it = mTimelines.find(inputEventId);
114 if (it == mTimelines.end()) {
115 // This could happen if we erased this event when duplicate events were detected. It's
116 // also possible that an app sent a bad (or late) 'Finish' signal, since it's free to do
117 // anything in its process. Just drop the report and move on.
118 return;
119 }
120
121 InputEventTimeline& timeline = it->second;
122 const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
123 if (connectionIt == timeline.connectionTimelines.end()) {
124 // Most likely case: app calls 'finishInputEvent' before it reports the graphics timeline
125 timeline.connectionTimelines.emplace(connectionToken,
126 ConnectionTimeline{deliveryTime, consumeTime,
127 finishTime});
128 } else {
129 // Already have a record for this connectionToken
130 ConnectionTimeline& connectionTimeline = connectionIt->second;
131 const bool success =
132 connectionTimeline.setDispatchTimeline(deliveryTime, consumeTime, finishTime);
133 if (!success) {
134 // We are receiving unreliable data from the app. Just delete the entire connection
135 // timeline for this event
136 timeline.connectionTimelines.erase(connectionIt);
137 }
138 }
139 }
140
trackGraphicsLatency(int32_t inputEventId,const sp<IBinder> & connectionToken,std::array<nsecs_t,GraphicsTimeline::SIZE> graphicsTimeline)141 void LatencyTracker::trackGraphicsLatency(
142 int32_t inputEventId, const sp<IBinder>& connectionToken,
143 std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline) {
144 const auto it = mTimelines.find(inputEventId);
145 if (it == mTimelines.end()) {
146 // This could happen if we erased this event when duplicate events were detected. It's
147 // also possible that an app sent a bad (or late) 'Timeline' signal, since it's free to do
148 // anything in its process. Just drop the report and move on.
149 return;
150 }
151
152 InputEventTimeline& timeline = it->second;
153 const auto connectionIt = timeline.connectionTimelines.find(connectionToken);
154 if (connectionIt == timeline.connectionTimelines.end()) {
155 timeline.connectionTimelines.emplace(connectionToken, std::move(graphicsTimeline));
156 } else {
157 // Most likely case
158 ConnectionTimeline& connectionTimeline = connectionIt->second;
159 const bool success = connectionTimeline.setGraphicsTimeline(std::move(graphicsTimeline));
160 if (!success) {
161 // We are receiving unreliable data from the app. Just delete the entire connection
162 // timeline for this event
163 timeline.connectionTimelines.erase(connectionIt);
164 }
165 }
166 }
167
168 /**
169 * We should use the current time 'now()' here to determine the age of the event, but instead we
170 * are using the latest 'eventTime' for efficiency since this time is already acquired, and
171 * 'trackListener' should happen soon after the event occurs.
172 */
reportAndPruneMatureRecords(nsecs_t newEventTime)173 void LatencyTracker::reportAndPruneMatureRecords(nsecs_t newEventTime) {
174 while (!mEventTimes.empty()) {
175 const auto& [oldestEventTime, oldestInputEventId] = *mEventTimes.begin();
176 if (isMatureEvent(oldestEventTime, /*now=*/newEventTime)) {
177 // Report and drop this event
178 const auto it = mTimelines.find(oldestInputEventId);
179 LOG_ALWAYS_FATAL_IF(it == mTimelines.end(),
180 "Event %" PRId32 " is in mEventTimes, but not in mTimelines",
181 oldestInputEventId);
182 const InputEventTimeline& timeline = it->second;
183 mTimelineProcessor->processTimeline(timeline);
184 mTimelines.erase(it);
185 mEventTimes.erase(mEventTimes.begin());
186 } else {
187 // If the oldest event does not need to be pruned, no events should be pruned.
188 return;
189 }
190 }
191 }
192
dump(const char * prefix) const193 std::string LatencyTracker::dump(const char* prefix) const {
194 return StringPrintf("%sLatencyTracker:\n", prefix) +
195 StringPrintf("%s mTimelines.size() = %zu\n", prefix, mTimelines.size()) +
196 StringPrintf("%s mEventTimes.size() = %zu\n", prefix, mEventTimes.size());
197 }
198
setInputDevices(const std::vector<InputDeviceInfo> & inputDevices)199 void LatencyTracker::setInputDevices(const std::vector<InputDeviceInfo>& inputDevices) {
200 mInputDevices = inputDevices;
201 }
202
203 } // namespace android::inputdispatcher
204