commit 9519bf1e32daf44a8f18ebd9a192447abf290001
author Alec Mouri <alecmouri@google.com> Fri Nov 15 16:54:44 2019 -0800
committer Alec Mouri <alecmouri@google.com> Thu Nov 21 21:33:47 2019 -0800
tree d0d23e901b88200454cb3670b65d7dbab51955d9
parent 478572d915d47f5857e2ce93ce577ae6ee97daab

[TimeStats] Track per-frame CPU time.

This measures from the beginning of the invalidate message, until
CompositionEngine::present finishes.

Bug: 144037240
Test: dumpsys SurfaceFlinger --timestats -dump
Change-Id: I1c686db9fa1746518c48810bf385041806ce06d2

services/surfaceflinger/tests/unittests/TimeStatsTest.cpp

diff --git a/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp b/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
index 7b60fa2..069344a 100644
--- a/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
+++ b/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
@@ -20,11 +20,11 @@
 #include <TimeStats/TimeStats.h>
 #include <gmock/gmock.h>
 #include <gtest/gtest.h>
-
 #include <log/log.h>
 #include <utils/String16.h>
 #include <utils/Vector.h>
 
+#include <chrono>
 #include <random>
 #include <unordered_set>
 
@@ -278,6 +278,31 @@
     EXPECT_EQ(2, histogramProto.time_millis());
 }
 
+TEST_F(TimeStatsTest, canInsertGlobalFrameDuration) {
+    EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
+
+    using namespace std::chrono_literals;
+
+    mTimeStats->setPowerMode(HWC_POWER_MODE_OFF);
+    mTimeStats
+            ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(1ms).count(),
+                                  std::chrono::duration_cast<std::chrono::nanoseconds>(5ms)
+                                          .count());
+    mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
+    mTimeStats
+            ->recordFrameDuration(std::chrono::duration_cast<std::chrono::nanoseconds>(3ms).count(),
+                                  std::chrono::duration_cast<std::chrono::nanoseconds>(6ms)
+                                          .count());
+
+    SFTimeStatsGlobalProto globalProto;
+    ASSERT_TRUE(globalProto.ParseFromString(inputCommand(InputCommand::DUMP_ALL, FMT_PROTO)));
+
+    ASSERT_EQ(1, globalProto.frame_duration_size());
+    const SFTimeStatsHistogramBucketProto& histogramProto = globalProto.frame_duration().Get(0);
+    EXPECT_EQ(1, histogramProto.frame_count());
+    EXPECT_EQ(3, histogramProto.time_millis());
+}
+
 TEST_F(TimeStatsTest, canInsertOneLayerTimeStats) {
     EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
 

services/surfaceflinger/tests/unittests/mock/MockTimeStats.h

diff --git a/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h b/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
index b1634a8..e94af49 100644
--- a/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
+++ b/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
@@ -34,6 +34,7 @@
     MOCK_METHOD0(incrementTotalFrames, void());
     MOCK_METHOD0(incrementMissedFrames, void());
     MOCK_METHOD0(incrementClientCompositionFrames, void());
+    MOCK_METHOD2(recordFrameDuration, void(nsecs_t, nsecs_t));
     MOCK_METHOD4(setPostTime, void(int32_t, uint64_t, const std::string&, nsecs_t));
     MOCK_METHOD3(setLatchTime, void(int32_t, uint64_t, nsecs_t));
     MOCK_METHOD3(setDesiredTime, void(int32_t, uint64_t, nsecs_t));