1 /*
2 * Copyright 2019 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 // TODO(b/129481165): remove the #pragma below and fix conversion issues
18 #pragma clang diagnostic push
19 #pragma clang diagnostic ignored "-Wconversion"
20 #pragma clang diagnostic ignored "-Wextra"
21
22 #undef LOG_TAG
23 #define LOG_TAG "LibSurfaceFlingerUnittests"
24
25 #include <FrameTracer/FrameTracer.h>
26 #include <gmock/gmock.h>
27 #include <gtest/gtest.h>
28 #include <log/log.h>
29 #include <perfetto/trace/trace.pb.h>
30
31 #include "libsurfaceflinger_unittest_main.h"
32
33 using namespace google::protobuf;
34
35 namespace android {
36 namespace {
37
38 class FrameTracerTest : public testing::Test {
39 public:
FrameTracerTest()40 FrameTracerTest() {
41 const ::testing::TestInfo* const test_info =
42 ::testing::UnitTest::GetInstance()->current_test_info();
43 ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
44
45 // Need to initialize tracing in process for testing, and only once per test suite.
46 static bool wasInitialized = false;
47 if (!wasInitialized) {
48 perfetto::TracingInitArgs args;
49 args.backends = perfetto::kInProcessBackend;
50 perfetto::Tracing::Initialize(args);
51 wasInitialized = true;
52 }
53 }
54
~FrameTracerTest()55 ~FrameTracerTest() {
56 const ::testing::TestInfo* const test_info =
57 ::testing::UnitTest::GetInstance()->current_test_info();
58 ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
59 }
60
SetUp()61 void SetUp() override {
62 mFrameTracer = std::make_unique<FrameTracer>();
63 mFrameTracer->registerDataSource();
64 }
65
TearDown()66 void TearDown() override { mFrameTracer.reset(); }
67
68 // Each tracing session can be used for a single block of Start -> Stop.
getTracingSessionForTest()69 static std::unique_ptr<perfetto::TracingSession> getTracingSessionForTest() {
70 perfetto::TraceConfig cfg;
71 cfg.set_duration_ms(500);
72 cfg.add_buffers()->set_size_kb(1024);
73 auto* ds_cfg = cfg.add_data_sources()->mutable_config();
74 ds_cfg->set_name(FrameTracer::kFrameTracerDataSource);
75
76 auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
77 tracingSession->Setup(cfg);
78 return tracingSession;
79 }
80
readGraphicsFramePacketsBlocking(perfetto::TracingSession * tracingSession)81 std::vector<perfetto::protos::TracePacket> readGraphicsFramePacketsBlocking(
82 perfetto::TracingSession* tracingSession) {
83 std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
84 perfetto::protos::Trace trace;
85 EXPECT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
86
87 std::vector<perfetto::protos::TracePacket> packets;
88 for (const auto& packet : trace.packet()) {
89 if (!packet.has_graphics_frame_event()) {
90 continue;
91 }
92 packets.emplace_back(packet);
93 }
94 return packets;
95 }
96
97 std::unique_ptr<FrameTracer> mFrameTracer;
98 FenceToFenceTimeMap fenceFactory;
99 };
100
TEST_F(FrameTracerTest,traceNewLayerStartsTrackingLayerWhenTracing)101 TEST_F(FrameTracerTest, traceNewLayerStartsTrackingLayerWhenTracing) {
102 EXPECT_EQ(mFrameTracer->miniDump(),
103 "FrameTracer miniDump:\nNumber of layers currently being traced is 0\n");
104
105 const std::string layerName = "co.layername#0";
106 const int32_t layerId = 5;
107 mFrameTracer->traceNewLayer(layerId, layerName);
108
109 EXPECT_EQ(mFrameTracer->miniDump(),
110 "FrameTracer miniDump:\nNumber of layers currently being traced is 0\n");
111
112 auto tracingSession = getTracingSessionForTest();
113 tracingSession->StartBlocking();
114 EXPECT_EQ(mFrameTracer->miniDump(),
115 "FrameTracer miniDump:\nNumber of layers currently being traced is 0\n");
116 mFrameTracer->traceNewLayer(layerId, layerName);
117 EXPECT_EQ(mFrameTracer->miniDump(),
118 "FrameTracer miniDump:\nNumber of layers currently being traced is 1\n");
119 tracingSession->StopBlocking();
120 }
121
TEST_F(FrameTracerTest,onDestroyRemovesTheTrackedLayer)122 TEST_F(FrameTracerTest, onDestroyRemovesTheTrackedLayer) {
123 EXPECT_EQ(mFrameTracer->miniDump(),
124 "FrameTracer miniDump:\nNumber of layers currently being traced is 0\n");
125
126 const std::string layerName = "co.layername#0";
127 const int32_t layerId = 5;
128 const int32_t secondlayerId = 6;
129
130 auto tracingSession = getTracingSessionForTest();
131 tracingSession->StartBlocking();
132 mFrameTracer->traceNewLayer(layerId, layerName);
133 mFrameTracer->traceNewLayer(secondlayerId, layerName);
134 EXPECT_EQ(mFrameTracer->miniDump(),
135 "FrameTracer miniDump:\nNumber of layers currently being traced is 2\n");
136 tracingSession->StopBlocking();
137
138 mFrameTracer->onDestroy(layerId);
139 EXPECT_EQ(mFrameTracer->miniDump(),
140 "FrameTracer miniDump:\nNumber of layers currently being traced is 1\n");
141 mFrameTracer->onDestroy(layerId);
142 EXPECT_EQ(mFrameTracer->miniDump(),
143 "FrameTracer miniDump:\nNumber of layers currently being traced is 1\n");
144 mFrameTracer->onDestroy(secondlayerId);
145 EXPECT_EQ(mFrameTracer->miniDump(),
146 "FrameTracer miniDump:\nNumber of layers currently being traced is 0\n");
147 }
148
TEST_F(FrameTracerTest,canTraceAfterAddingLayer)149 TEST_F(FrameTracerTest, canTraceAfterAddingLayer) {
150 const std::string layerName = "co.layername#0";
151 const int32_t layerId = 1;
152 const uint32_t bufferID = 2;
153 const uint64_t frameNumber = 3;
154 const nsecs_t timestamp = 4;
155 const nsecs_t duration = 5;
156 const auto type = FrameTracer::FrameEvent::POST;
157
158 {
159 auto tracingSession = getTracingSessionForTest();
160
161 tracingSession->StartBlocking();
162 mFrameTracer->traceTimestamp(layerId, bufferID, frameNumber, timestamp, type, duration);
163 // Create second trace packet to finalize the previous one.
164 mFrameTracer->traceTimestamp(layerId, 0, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
165 tracingSession->StopBlocking();
166
167 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
168 EXPECT_EQ(packets.size(), 0);
169 }
170
171 {
172 auto tracingSession = getTracingSessionForTest();
173
174 tracingSession->StartBlocking();
175 mFrameTracer->traceNewLayer(layerId, layerName);
176 mFrameTracer->traceTimestamp(layerId, bufferID, frameNumber, timestamp, type, duration);
177 // Create second trace packet to finalize the previous one.
178 mFrameTracer->traceTimestamp(layerId, 0, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
179 tracingSession->StopBlocking();
180
181 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
182 EXPECT_EQ(packets.size(), 1);
183
184 const auto& packet = packets[0];
185 ASSERT_TRUE(packet.has_timestamp());
186 EXPECT_EQ(packet.timestamp(), timestamp);
187 ASSERT_TRUE(packet.has_graphics_frame_event());
188 const auto& frame_event = packet.graphics_frame_event();
189 ASSERT_TRUE(frame_event.has_buffer_event());
190 const auto& buffer_event = frame_event.buffer_event();
191 ASSERT_TRUE(buffer_event.has_buffer_id());
192 EXPECT_EQ(buffer_event.buffer_id(), bufferID);
193 ASSERT_TRUE(buffer_event.has_frame_number());
194 EXPECT_EQ(buffer_event.frame_number(), frameNumber);
195 ASSERT_TRUE(buffer_event.has_type());
196 EXPECT_EQ(buffer_event.type(), perfetto::protos::GraphicsFrameEvent_BufferEventType(type));
197 ASSERT_TRUE(buffer_event.has_duration_ns());
198 EXPECT_EQ(buffer_event.duration_ns(), duration);
199 }
200 }
201
TEST_F(FrameTracerTest,traceFenceTriggersOnNextTraceAfterFenceFired)202 TEST_F(FrameTracerTest, traceFenceTriggersOnNextTraceAfterFenceFired) {
203 const std::string layerName = "co.layername#0";
204 const int32_t layerId = 5;
205 const uint32_t bufferID = 4;
206 const uint64_t frameNumber = 3;
207 const auto type = FrameTracer::FrameEvent::ACQUIRE_FENCE;
208
209 {
210 auto fenceTime = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
211 fenceFactory.signalAllForTest(Fence::NO_FENCE, Fence::SIGNAL_TIME_PENDING);
212 auto tracingSession = getTracingSessionForTest();
213 tracingSession->StartBlocking();
214 // Trace.
215 mFrameTracer->traceNewLayer(layerId, layerName);
216 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fenceTime, type);
217 // Create extra trace packet to (hopefully not) trigger and finalize the fence packet.
218 mFrameTracer->traceTimestamp(layerId, bufferID, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
219 tracingSession->StopBlocking();
220
221 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
222 EXPECT_EQ(packets.size(), 0);
223 }
224
225 {
226 auto fenceTime = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
227 auto tracingSession = getTracingSessionForTest();
228 tracingSession->StartBlocking();
229 mFrameTracer->traceNewLayer(layerId, layerName);
230 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fenceTime, type);
231 const nsecs_t timestamp = systemTime();
232 fenceFactory.signalAllForTest(Fence::NO_FENCE, timestamp);
233 // Create extra trace packet to trigger and finalize fence trace packets.
234 mFrameTracer->traceTimestamp(layerId, bufferID, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
235 tracingSession->StopBlocking();
236
237 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
238 EXPECT_EQ(packets.size(), 2); // Two packets because of the extra trace made above.
239
240 const auto& packet = packets[1];
241 ASSERT_TRUE(packet.has_timestamp());
242 EXPECT_EQ(packet.timestamp(), timestamp);
243 ASSERT_TRUE(packet.has_graphics_frame_event());
244 const auto& frame_event = packet.graphics_frame_event();
245 ASSERT_TRUE(frame_event.has_buffer_event());
246 const auto& buffer_event = frame_event.buffer_event();
247 ASSERT_TRUE(buffer_event.has_buffer_id());
248 EXPECT_EQ(buffer_event.buffer_id(), bufferID);
249 ASSERT_TRUE(buffer_event.has_frame_number());
250 EXPECT_EQ(buffer_event.frame_number(), frameNumber);
251 ASSERT_TRUE(buffer_event.has_type());
252 EXPECT_EQ(buffer_event.type(), perfetto::protos::GraphicsFrameEvent_BufferEventType(type));
253 EXPECT_FALSE(buffer_event.has_duration_ns());
254 }
255 }
256
TEST_F(FrameTracerTest,traceFenceWithStartTimeAfterSignalTime_ShouldHaveNoDuration)257 TEST_F(FrameTracerTest, traceFenceWithStartTimeAfterSignalTime_ShouldHaveNoDuration) {
258 const std::string layerName = "co.layername#0";
259 const int32_t layerId = 5;
260 const uint32_t bufferID = 4;
261 const uint64_t frameNumber = 3;
262 const auto type = FrameTracer::FrameEvent::ACQUIRE_FENCE;
263
264 auto tracingSession = getTracingSessionForTest();
265
266 tracingSession->StartBlocking();
267 mFrameTracer->traceNewLayer(layerId, layerName);
268
269 // traceFence called after fence signalled.
270 const nsecs_t signalTime1 = systemTime();
271 const nsecs_t startTime1 = signalTime1 + 100000;
272 auto fence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
273 fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime1);
274 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fence1, type, startTime1);
275
276 // traceFence called before fence signalled.
277 const nsecs_t signalTime2 = systemTime();
278 const nsecs_t startTime2 = signalTime2 + 100000;
279 auto fence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
280 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fence2, type, startTime2);
281 fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime2);
282
283 // Create extra trace packet to trigger and finalize fence trace packets.
284 mFrameTracer->traceTimestamp(layerId, bufferID, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
285 tracingSession->StopBlocking();
286
287 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
288 EXPECT_EQ(packets.size(), 2);
289
290 const auto& packet1 = packets[0];
291 ASSERT_TRUE(packet1.has_timestamp());
292 EXPECT_EQ(packet1.timestamp(), signalTime1);
293 ASSERT_TRUE(packet1.has_graphics_frame_event());
294 ASSERT_TRUE(packet1.graphics_frame_event().has_buffer_event());
295 ASSERT_FALSE(packet1.graphics_frame_event().buffer_event().has_duration_ns());
296
297 const auto& packet2 = packets[1];
298 ASSERT_TRUE(packet2.has_timestamp());
299 EXPECT_EQ(packet2.timestamp(), signalTime2);
300 ASSERT_TRUE(packet2.has_graphics_frame_event());
301 ASSERT_TRUE(packet2.graphics_frame_event().has_buffer_event());
302 ASSERT_FALSE(packet2.graphics_frame_event().buffer_event().has_duration_ns());
303 }
304
TEST_F(FrameTracerTest,traceFenceOlderThanDeadline_ShouldBeIgnored)305 TEST_F(FrameTracerTest, traceFenceOlderThanDeadline_ShouldBeIgnored) {
306 const std::string layerName = "co.layername#0";
307 const int32_t layerId = 5;
308 const uint32_t bufferID = 4;
309 const uint64_t frameNumber = 3;
310 const auto type = FrameTracer::FrameEvent::ACQUIRE_FENCE;
311 const nsecs_t signalTime = systemTime() - FrameTracer::kFenceSignallingDeadline;
312
313 auto tracingSession = getTracingSessionForTest();
314 auto fence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
315
316 tracingSession->StartBlocking();
317 mFrameTracer->traceNewLayer(layerId, layerName);
318 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fence, type);
319 fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime);
320 // Create extra trace packet to trigger and finalize any previous fence packets.
321 mFrameTracer->traceTimestamp(layerId, bufferID, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
322 tracingSession->StopBlocking();
323
324 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
325 EXPECT_EQ(packets.size(), 0);
326 }
327
TEST_F(FrameTracerTest,traceFenceWithValidStartTime_ShouldHaveCorrectDuration)328 TEST_F(FrameTracerTest, traceFenceWithValidStartTime_ShouldHaveCorrectDuration) {
329 const std::string layerName = "co.layername#0";
330 const int32_t layerId = 5;
331 const uint32_t bufferID = 4;
332 const uint64_t frameNumber = 3;
333 const auto type = FrameTracer::FrameEvent::ACQUIRE_FENCE;
334 const nsecs_t duration = 1234;
335
336 auto tracingSession = getTracingSessionForTest();
337
338 tracingSession->StartBlocking();
339 mFrameTracer->traceNewLayer(layerId, layerName);
340
341 // traceFence called after fence signalled.
342 const nsecs_t signalTime1 = systemTime();
343 const nsecs_t startTime1 = signalTime1 - duration;
344 auto fence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
345 fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime1);
346 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fence1, type, startTime1);
347
348 // traceFence called before fence signalled.
349 const nsecs_t signalTime2 = systemTime();
350 const nsecs_t startTime2 = signalTime2 - duration;
351 auto fence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
352 mFrameTracer->traceFence(layerId, bufferID, frameNumber, fence2, type, startTime2);
353 fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime2);
354
355 // Create extra trace packet to trigger and finalize fence trace packets.
356 mFrameTracer->traceTimestamp(layerId, bufferID, 0, 0, FrameTracer::FrameEvent::UNSPECIFIED);
357 tracingSession->StopBlocking();
358
359 auto packets = readGraphicsFramePacketsBlocking(tracingSession.get());
360 EXPECT_EQ(packets.size(), 2);
361
362 const auto& packet1 = packets[0];
363 ASSERT_TRUE(packet1.has_timestamp());
364 EXPECT_EQ(packet1.timestamp(), startTime1);
365 ASSERT_TRUE(packet1.has_graphics_frame_event());
366 ASSERT_TRUE(packet1.graphics_frame_event().has_buffer_event());
367 ASSERT_TRUE(packet1.graphics_frame_event().buffer_event().has_duration_ns());
368 const auto& buffer_event1 = packet1.graphics_frame_event().buffer_event();
369 EXPECT_EQ(buffer_event1.duration_ns(), duration);
370
371 const auto& packet2 = packets[1];
372 ASSERT_TRUE(packet2.has_timestamp());
373 EXPECT_EQ(packet2.timestamp(), startTime2);
374 ASSERT_TRUE(packet2.has_graphics_frame_event());
375 ASSERT_TRUE(packet2.graphics_frame_event().has_buffer_event());
376 ASSERT_TRUE(packet2.graphics_frame_event().buffer_event().has_duration_ns());
377 const auto& buffer_event2 = packet2.graphics_frame_event().buffer_event();
378 EXPECT_EQ(buffer_event2.duration_ns(), duration);
379 }
380
381 } // namespace
382 } // namespace android
383
384 // TODO(b/129481165): remove the #pragma below and fix conversion issues
385 #pragma clang diagnostic pop // ignored "-Wconversion -Wextra"
386