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