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 #include "../dispatcher/LatencyTracker.h"
18 #include "../InputDeviceMetricsSource.h"
19 
20 #include <android-base/properties.h>
21 #include <binder/Binder.h>
22 #include <gtest/gtest.h>
23 #include <inttypes.h>
24 #include <linux/input.h>
25 #include <log/log.h>
26 
27 #define TAG "LatencyTracker_test"
28 
29 using android::base::HwTimeoutMultiplier;
30 using android::inputdispatcher::InputEventTimeline;
31 using android::inputdispatcher::LatencyTracker;
32 
33 namespace android::inputdispatcher {
34 
35 namespace {
36 
37 constexpr DeviceId DEVICE_ID = 100;
38 
generateTestDeviceInfo(uint16_t vendorId,uint16_t productId,DeviceId deviceId)39 static InputDeviceInfo generateTestDeviceInfo(uint16_t vendorId, uint16_t productId,
40                                               DeviceId deviceId) {
41     InputDeviceIdentifier identifier;
42     identifier.vendor = vendorId;
43     identifier.product = productId;
44     auto info = InputDeviceInfo();
45     info.initialize(deviceId, /*generation=*/1, /*controllerNumber=*/1, identifier, "Test Device",
46                     /*isExternal=*/false, /*hasMic=*/false, ui::LogicalDisplayId::INVALID);
47     return info;
48 }
49 
setDefaultInputDeviceInfo(LatencyTracker & tracker)50 void setDefaultInputDeviceInfo(LatencyTracker& tracker) {
51     InputDeviceInfo deviceInfo = generateTestDeviceInfo(
52             /*vendorId=*/0, /*productId=*/0, DEVICE_ID);
53     tracker.setInputDevices({deviceInfo});
54 }
55 
56 } // namespace
57 
58 const std::chrono::duration ANR_TIMEOUT = std::chrono::milliseconds(
59         android::os::IInputConstants::UNMULTIPLIED_DEFAULT_DISPATCHING_TIMEOUT_MILLIS *
60         HwTimeoutMultiplier());
61 
getTestTimeline()62 InputEventTimeline getTestTimeline() {
63     InputEventTimeline t(
64             /*isDown=*/true,
65             /*eventTime=*/2,
66             /*readTime=*/3,
67             /*vendorId=*/0,
68             /*productId=*/0,
69             /*sources=*/{InputDeviceUsageSource::UNKNOWN});
70     ConnectionTimeline expectedCT(/*deliveryTime=*/6, /*consumeTime=*/7, /*finishTime=*/8);
71     std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
72     graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 9;
73     graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 10;
74     expectedCT.setGraphicsTimeline(std::move(graphicsTimeline));
75     t.connectionTimelines.emplace(sp<BBinder>::make(), std::move(expectedCT));
76     return t;
77 }
78 
79 // --- LatencyTrackerTest ---
80 class LatencyTrackerTest : public testing::Test, public InputEventTimelineProcessor {
81 protected:
82     std::unique_ptr<LatencyTracker> mTracker;
83     sp<IBinder> connection1;
84     sp<IBinder> connection2;
85 
SetUp()86     void SetUp() override {
87         connection1 = sp<BBinder>::make();
88         connection2 = sp<BBinder>::make();
89 
90         mTracker = std::make_unique<LatencyTracker>(this);
91         setDefaultInputDeviceInfo(*mTracker);
92     }
TearDown()93     void TearDown() override {}
94 
95     void triggerEventReporting(nsecs_t lastEventTime);
96 
97     void assertReceivedTimeline(const InputEventTimeline& timeline);
98     /**
99      * Timelines can be received in any order (order is not guaranteed). So if we are expecting more
100      * than 1 timeline, use this function to check that the set of received timelines matches
101      * what we expected.
102      */
103     void assertReceivedTimelines(const std::vector<InputEventTimeline>& timelines);
104 
105 private:
processTimeline(const InputEventTimeline & timeline)106     void processTimeline(const InputEventTimeline& timeline) override {
107         mReceivedTimelines.push_back(timeline);
108     }
109     std::deque<InputEventTimeline> mReceivedTimelines;
110 };
111 
112 /**
113  * Send an event that would trigger the reporting of all of the events that are at least as old as
114  * the provided 'lastEventTime'.
115  */
triggerEventReporting(nsecs_t lastEventTime)116 void LatencyTrackerTest::triggerEventReporting(nsecs_t lastEventTime) {
117     const nsecs_t triggerEventTime =
118             lastEventTime + std::chrono::nanoseconds(ANR_TIMEOUT).count() + 1;
119     mTracker->trackListener(/*inputEventId=*/1, /*isDown=*/true, triggerEventTime,
120                             /*readTime=*/3, DEVICE_ID,
121                             /*sources=*/{InputDeviceUsageSource::UNKNOWN});
122 }
123 
assertReceivedTimeline(const InputEventTimeline & timeline)124 void LatencyTrackerTest::assertReceivedTimeline(const InputEventTimeline& timeline) {
125     ASSERT_FALSE(mReceivedTimelines.empty());
126     const InputEventTimeline& t = mReceivedTimelines.front();
127     ASSERT_EQ(timeline, t);
128     mReceivedTimelines.pop_front();
129 }
130 
131 /**
132  * We are essentially comparing two multisets, but without constructing them.
133  * This comparison is inefficient, but it avoids having to construct a set, and also avoids the
134  * declaration of copy constructor for ConnectionTimeline.
135  * We ensure that collections A and B have the same size, that for every element in A, there is an
136  * equal element in B, and for every element in B there is an equal element in A.
137  */
assertReceivedTimelines(const std::vector<InputEventTimeline> & timelines)138 void LatencyTrackerTest::assertReceivedTimelines(const std::vector<InputEventTimeline>& timelines) {
139     ASSERT_EQ(timelines.size(), mReceivedTimelines.size());
140     for (const InputEventTimeline& expectedTimeline : timelines) {
141         bool found = false;
142         for (const InputEventTimeline& receivedTimeline : mReceivedTimelines) {
143             if (receivedTimeline == expectedTimeline) {
144                 found = true;
145                 break;
146             }
147         }
148         ASSERT_TRUE(found) << "Could not find expected timeline with eventTime="
149                            << expectedTimeline.eventTime;
150     }
151     for (const InputEventTimeline& receivedTimeline : mReceivedTimelines) {
152         bool found = false;
153         for (const InputEventTimeline& expectedTimeline : timelines) {
154             if (receivedTimeline == expectedTimeline) {
155                 found = true;
156                 break;
157             }
158         }
159         ASSERT_TRUE(found) << "Could not find received timeline with eventTime="
160                            << receivedTimeline.eventTime;
161     }
162     mReceivedTimelines.clear();
163 }
164 
165 /**
166  * Ensure that calling 'trackListener' in isolation only creates an inputflinger timeline, without
167  * any additional ConnectionTimeline's.
168  */
TEST_F(LatencyTrackerTest,TrackListener_DoesNotTriggerReporting)169 TEST_F(LatencyTrackerTest, TrackListener_DoesNotTriggerReporting) {
170     mTracker->trackListener(/*inputEventId=*/1, /*isDown=*/false, /*eventTime=*/2,
171                             /*readTime=*/3, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN});
172     triggerEventReporting(/*eventTime=*/2);
173     assertReceivedTimeline(InputEventTimeline{/*isDown=*/false, /*eventTime=*/2,
174                                               /*readTime=*/3, /*vendorId=*/0, /*productID=*/0,
175                                               /*sources=*/{InputDeviceUsageSource::UNKNOWN}});
176 }
177 
178 /**
179  * A single call to trackFinishedEvent should not cause a timeline to be reported.
180  */
TEST_F(LatencyTrackerTest,TrackFinishedEvent_DoesNotTriggerReporting)181 TEST_F(LatencyTrackerTest, TrackFinishedEvent_DoesNotTriggerReporting) {
182     mTracker->trackFinishedEvent(/*inputEventId=*/1, connection1, /*deliveryTime=*/2,
183                                  /*consumeTime=*/3, /*finishTime=*/4);
184     triggerEventReporting(/*eventTime=*/4);
185     assertReceivedTimelines({});
186 }
187 
188 /**
189  * A single call to trackGraphicsLatency should not cause a timeline to be reported.
190  */
TEST_F(LatencyTrackerTest,TrackGraphicsLatency_DoesNotTriggerReporting)191 TEST_F(LatencyTrackerTest, TrackGraphicsLatency_DoesNotTriggerReporting) {
192     std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline;
193     graphicsTimeline[GraphicsTimeline::GPU_COMPLETED_TIME] = 2;
194     graphicsTimeline[GraphicsTimeline::PRESENT_TIME] = 3;
195     mTracker->trackGraphicsLatency(/*inputEventId=*/1, connection2, graphicsTimeline);
196     triggerEventReporting(/*eventTime=*/3);
197     assertReceivedTimelines({});
198 }
199 
TEST_F(LatencyTrackerTest,TrackAllParameters_ReportsFullTimeline)200 TEST_F(LatencyTrackerTest, TrackAllParameters_ReportsFullTimeline) {
201     constexpr int32_t inputEventId = 1;
202     InputEventTimeline expected = getTestTimeline();
203 
204     const auto& [connectionToken, expectedCT] = *expected.connectionTimelines.begin();
205 
206     mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime,
207                             DEVICE_ID, {InputDeviceUsageSource::UNKNOWN});
208     mTracker->trackFinishedEvent(inputEventId, connectionToken, expectedCT.deliveryTime,
209                                  expectedCT.consumeTime, expectedCT.finishTime);
210     mTracker->trackGraphicsLatency(inputEventId, connectionToken, expectedCT.graphicsTimeline);
211 
212     triggerEventReporting(expected.eventTime);
213     assertReceivedTimeline(expected);
214 }
215 
216 /**
217  * Send 2 events with the same inputEventId, but different eventTime's. Ensure that no crash occurs,
218  * and that the tracker drops such events completely.
219  */
TEST_F(LatencyTrackerTest,WhenDuplicateEventsAreReported_DoesNotCrash)220 TEST_F(LatencyTrackerTest, WhenDuplicateEventsAreReported_DoesNotCrash) {
221     constexpr nsecs_t inputEventId = 1;
222     constexpr nsecs_t readTime = 3; // does not matter for this test
223     constexpr bool isDown = true;   // does not matter for this test
224 
225     // In the following 2 calls to trackListener, the inputEventId's are the same, but event times
226     // are different.
227     mTracker->trackListener(inputEventId, isDown, /*eventTime=*/1, readTime, DEVICE_ID,
228                             {InputDeviceUsageSource::UNKNOWN});
229     mTracker->trackListener(inputEventId, isDown, /*eventTime=*/2, readTime, DEVICE_ID,
230                             {InputDeviceUsageSource::UNKNOWN});
231 
232     triggerEventReporting(/*eventTime=*/2);
233     // Since we sent duplicate input events, the tracker should just delete all of them, because it
234     // does not have enough information to properly track them.
235     assertReceivedTimelines({});
236 }
237 
TEST_F(LatencyTrackerTest,MultipleEvents_AreReportedConsistently)238 TEST_F(LatencyTrackerTest, MultipleEvents_AreReportedConsistently) {
239     constexpr int32_t inputEventId1 = 1;
240     InputEventTimeline timeline1(
241             /*isDown*/ true,
242             /*eventTime*/ 2,
243             /*readTime*/ 3,
244             /*vendorId=*/0,
245             /*productId=*/0,
246             /*sources=*/{InputDeviceUsageSource::UNKNOWN});
247     timeline1.connectionTimelines.emplace(connection1,
248                                           ConnectionTimeline(/*deliveryTime*/ 6, /*consumeTime*/ 7,
249                                                              /*finishTime*/ 8));
250     ConnectionTimeline& connectionTimeline1 = timeline1.connectionTimelines.begin()->second;
251     std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline1;
252     graphicsTimeline1[GraphicsTimeline::GPU_COMPLETED_TIME] = 9;
253     graphicsTimeline1[GraphicsTimeline::PRESENT_TIME] = 10;
254     connectionTimeline1.setGraphicsTimeline(std::move(graphicsTimeline1));
255 
256     constexpr int32_t inputEventId2 = 10;
257     InputEventTimeline timeline2(
258             /*isDown=*/false,
259             /*eventTime=*/20,
260             /*readTime=*/30,
261             /*vendorId=*/0,
262             /*productId=*/0,
263             /*sources=*/{InputDeviceUsageSource::UNKNOWN});
264     timeline2.connectionTimelines.emplace(connection2,
265                                           ConnectionTimeline(/*deliveryTime=*/60,
266                                                              /*consumeTime=*/70,
267                                                              /*finishTime=*/80));
268     ConnectionTimeline& connectionTimeline2 = timeline2.connectionTimelines.begin()->second;
269     std::array<nsecs_t, GraphicsTimeline::SIZE> graphicsTimeline2;
270     graphicsTimeline2[GraphicsTimeline::GPU_COMPLETED_TIME] = 90;
271     graphicsTimeline2[GraphicsTimeline::PRESENT_TIME] = 100;
272     connectionTimeline2.setGraphicsTimeline(std::move(graphicsTimeline2));
273 
274     // Start processing first event
275     mTracker->trackListener(inputEventId1, timeline1.isDown, timeline1.eventTime,
276                             timeline1.readTime, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN});
277     // Start processing second event
278     mTracker->trackListener(inputEventId2, timeline2.isDown, timeline2.eventTime,
279                             timeline2.readTime, DEVICE_ID, {InputDeviceUsageSource::UNKNOWN});
280     mTracker->trackFinishedEvent(inputEventId1, connection1, connectionTimeline1.deliveryTime,
281                                  connectionTimeline1.consumeTime, connectionTimeline1.finishTime);
282 
283     mTracker->trackFinishedEvent(inputEventId2, connection2, connectionTimeline2.deliveryTime,
284                                  connectionTimeline2.consumeTime, connectionTimeline2.finishTime);
285     mTracker->trackGraphicsLatency(inputEventId1, connection1,
286                                    connectionTimeline1.graphicsTimeline);
287     mTracker->trackGraphicsLatency(inputEventId2, connection2,
288                                    connectionTimeline2.graphicsTimeline);
289     // Now both events should be completed
290     triggerEventReporting(timeline2.eventTime);
291     assertReceivedTimelines({timeline1, timeline2});
292 }
293 
294 /**
295  * Check that LatencyTracker consistently tracks events even if there are many incomplete events.
296  */
TEST_F(LatencyTrackerTest,IncompleteEvents_AreHandledConsistently)297 TEST_F(LatencyTrackerTest, IncompleteEvents_AreHandledConsistently) {
298     InputEventTimeline timeline = getTestTimeline();
299     std::vector<InputEventTimeline> expectedTimelines;
300     const ConnectionTimeline& expectedCT = timeline.connectionTimelines.begin()->second;
301     const sp<IBinder>& token = timeline.connectionTimelines.begin()->first;
302 
303     for (size_t i = 1; i <= 100; i++) {
304         mTracker->trackListener(/*inputEventId=*/i, timeline.isDown, timeline.eventTime,
305                                 timeline.readTime, /*deviceId=*/DEVICE_ID,
306                                 /*sources=*/{InputDeviceUsageSource::UNKNOWN});
307         expectedTimelines.push_back(InputEventTimeline{timeline.isDown, timeline.eventTime,
308                                                        timeline.readTime, timeline.vendorId,
309                                                        timeline.productId, timeline.sources});
310     }
311     // Now, complete the first event that was sent.
312     mTracker->trackFinishedEvent(/*inputEventId=*/1, token, expectedCT.deliveryTime,
313                                  expectedCT.consumeTime, expectedCT.finishTime);
314     mTracker->trackGraphicsLatency(/*inputEventId=*/1, token, expectedCT.graphicsTimeline);
315 
316     expectedTimelines[0].connectionTimelines.emplace(token, std::move(expectedCT));
317     triggerEventReporting(timeline.eventTime);
318     assertReceivedTimelines(expectedTimelines);
319 }
320 
321 /**
322  * For simplicity of the implementation, LatencyTracker only starts tracking an event when
323  * 'trackListener' is invoked.
324  * Both 'trackFinishedEvent' and 'trackGraphicsLatency' should not start a new event.
325  * If they are received before 'trackListener' (which should not be possible), they are ignored.
326  */
TEST_F(LatencyTrackerTest,EventsAreTracked_WhenTrackListenerIsCalledFirst)327 TEST_F(LatencyTrackerTest, EventsAreTracked_WhenTrackListenerIsCalledFirst) {
328     constexpr int32_t inputEventId = 1;
329     InputEventTimeline expected = getTestTimeline();
330     const ConnectionTimeline& expectedCT = expected.connectionTimelines.begin()->second;
331     mTracker->trackFinishedEvent(inputEventId, connection1, expectedCT.deliveryTime,
332                                  expectedCT.consumeTime, expectedCT.finishTime);
333     mTracker->trackGraphicsLatency(inputEventId, connection1, expectedCT.graphicsTimeline);
334 
335     mTracker->trackListener(inputEventId, expected.isDown, expected.eventTime, expected.readTime,
336                             DEVICE_ID, {InputDeviceUsageSource::UNKNOWN});
337     triggerEventReporting(expected.eventTime);
338     assertReceivedTimeline(InputEventTimeline{expected.isDown, expected.eventTime,
339                                               expected.readTime, expected.vendorId,
340                                               expected.productId, expected.sources});
341 }
342 
343 /**
344  * Check that LatencyTracker has the received timeline that contains the correctly
345  * resolved product ID, vendor ID and source for a particular device ID from
346  * among a list of devices.
347  */
TEST_F(LatencyTrackerTest,TrackListenerCheck_DeviceInfoFieldsInputEventTimeline)348 TEST_F(LatencyTrackerTest, TrackListenerCheck_DeviceInfoFieldsInputEventTimeline) {
349     constexpr int32_t inputEventId = 1;
350     InputEventTimeline timeline(
351             /*isDown*/ true, /*eventTime*/ 2, /*readTime*/ 3,
352             /*vendorId=*/50, /*productId=*/60,
353             /*sources=*/
354             {InputDeviceUsageSource::TOUCHSCREEN, InputDeviceUsageSource::STYLUS_DIRECT});
355     InputDeviceInfo deviceInfo1 = generateTestDeviceInfo(
356             /*vendorId=*/5, /*productId=*/6, /*deviceId=*/DEVICE_ID + 1);
357     InputDeviceInfo deviceInfo2 = generateTestDeviceInfo(
358             /*vendorId=*/50, /*productId=*/60, /*deviceId=*/DEVICE_ID);
359 
360     mTracker->setInputDevices({deviceInfo1, deviceInfo2});
361     mTracker->trackListener(inputEventId, timeline.isDown, timeline.eventTime, timeline.readTime,
362                             DEVICE_ID,
363                             {InputDeviceUsageSource::TOUCHSCREEN,
364                              InputDeviceUsageSource::STYLUS_DIRECT});
365     triggerEventReporting(timeline.eventTime);
366     assertReceivedTimeline(timeline);
367 }
368 
369 } // namespace android::inputdispatcher
370