Merge "[SfStats] Add frame duration and renderengine timing to statsd" (96181f90) · Commits · e / os / android_frameworks_native

services/surfaceflinger/TimeStats/TimeStats.cpp

+31 −22

Original line number	Diff line number	Diff line
		@@ -55,28 +55,6 @@ AStatsManager_PullAtomCallbackReturn TimeStats::pullAtomCallback(int32_t atom_ta
		return result;
		}

		AStatsManager_PullAtomCallbackReturn TimeStats::populateGlobalAtom(AStatsEventList* data) {
		std::lock_guard<std::mutex> lock(mMutex);

		if (mTimeStats.statsStart == 0) {
		return AStatsManager_PULL_SKIP;
		}
		flushPowerTimeLocked();

		AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
		mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
		mStatsDelegate->statsEventWriteInt32(event, mTimeStats.displayEventConnectionsCount);
		mStatsDelegate->statsEventBuild(event);
		clearGlobalLocked();

		return AStatsManager_PULL_SUCCESS;
		}

		namespace {
		// Histograms align with the order of fields in SurfaceflingerStatsLayerInfo.
		const std::array<std::string, 6> kHistogramNames = {
		@@ -112,6 +90,37 @@ std::string histogramToProtoByteString(const std::unordered_map<int32_t, int32_t
		}
		} // namespace

		AStatsManager_PullAtomCallbackReturn TimeStats::populateGlobalAtom(AStatsEventList* data) {
		std::lock_guard<std::mutex> lock(mMutex);

		if (mTimeStats.statsStart == 0) {
		return AStatsManager_PULL_SKIP;
		}
		flushPowerTimeLocked();

		AStatsEvent* event = mStatsDelegate->addStatsEventToPullData(data);
		mStatsDelegate->statsEventSetAtomId(event, android::util::SURFACEFLINGER_STATS_GLOBAL_INFO);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.totalFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.missedFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.clientCompositionFrames);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.displayOnTime);
		mStatsDelegate->statsEventWriteInt64(event, mTimeStats.presentToPresent.totalTime());
		mStatsDelegate->statsEventWriteInt32(event, mTimeStats.displayEventConnectionsCount);
		std::string frameDurationBytes =
		histogramToProtoByteString(mTimeStats.frameDuration.hist, mMaxPulledHistogramBuckets);
		mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)frameDurationBytes.c_str(),
		frameDurationBytes.size());
		std::string renderEngineTimingBytes =
		histogramToProtoByteString(mTimeStats.renderEngineTiming.hist,
		mMaxPulledHistogramBuckets);
		mStatsDelegate->statsEventWriteByteArray(event, (const uint8_t*)renderEngineTimingBytes.c_str(),
		renderEngineTimingBytes.size());
		mStatsDelegate->statsEventBuild(event);
		clearGlobalLocked();

		return AStatsManager_PULL_SUCCESS;
		}

		AStatsManager_PullAtomCallbackReturn TimeStats::populateLayerAtom(AStatsEventList* data) {
		std::lock_guard<std::mutex> lock(mMutex);

services/surfaceflinger/tests/unittests/TimeStatsTest.cpp

+61 −44

Original line number	Diff line number	Diff line
		@@ -797,6 +797,49 @@ TEST_F(TimeStatsTest, canDumpWithInvalidMaxLayers) {
		ASSERT_EQ(0, globalProto.stats_size());
		}

		namespace {
		std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
		const std::vector<int32_t>& frameCounts) {
		util::ProtoOutputStream proto;
		for (int i = 0; i < times.size(); i++) {
		ALOGE("Writing time: %d", times[i]);
		proto.write(util::FIELD_TYPE_INT32 \| util::FIELD_COUNT_REPEATED \| 1 /* field id */,
		(int32_t)times[i]);
		ALOGE("Writing count: %d", frameCounts[i]);
		proto.write(util::FIELD_TYPE_INT64 \| util::FIELD_COUNT_REPEATED \| 2 /* field id */,
		(int64_t)frameCounts[i]);
		}
		std::string byteString;
		proto.serializeToString(&byteString);
		return byteString;
		}

		std::string dumpByteStringHex(const std::string& str) {
		std::stringstream ss;
		ss << std::hex;
		for (const char& c : str) {
		ss << (int)c << " ";
		}

		return ss.str();
		}

		} // namespace

		MATCHER_P2(BytesEq, bytes, size, "") {
		std::string expected;
		expected.append((const char*)bytes, size);
		std::string actual;
		actual.append((const char*)arg, size);

		*result_listener << "Bytes are not equal! \n";
		*result_listener << "size: " << size << "\n";
		*result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
		*result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";

		return expected == actual;
		}

		TEST_F(TimeStatsTest, globalStatsCallback) {
		constexpr size_t TOTAL_FRAMES = 5;
		constexpr size_t MISSED_FRAMES = 4;
		@@ -817,8 +860,11 @@ TEST_F(TimeStatsTest, globalStatsCallback) {
		}

		mTimeStats->recordDisplayEventConnectionCount(DISPLAY_EVENT_CONNECTIONS);

		mTimeStats->setPowerMode(HWC_POWER_MODE_NORMAL);
		mTimeStats->recordFrameDuration(1000000, 3000000);
		mTimeStats->recordRenderEngineDuration(2000000, 4000000);
		mTimeStats->recordRenderEngineDuration(2000000, std::make_shared<FenceTime>(3000000));

		mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(3000000));
		mTimeStats->setPresentFenceGlobal(std::make_shared<FenceTime>(5000000));

		@@ -828,6 +874,9 @@ TEST_F(TimeStatsTest, globalStatsCallback) {
		EXPECT_NE(nullptr, mDelegate->mCallback);
		EXPECT_EQ(mTimeStats.get(), mDelegate->mCookie);

		std::string expectedFrameDuration = buildExpectedHistogramBytestring({2}, {1});
		std::string expectedRenderEngineTiming = buildExpectedHistogramBytestring({1, 2}, {1, 1});

		{
		InSequence seq;
		EXPECT_CALL(*mDelegate,
		@@ -839,6 +888,17 @@ TEST_F(TimeStatsTest, globalStatsCallback) {
		EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, _));
		EXPECT_CALL(*mDelegate, statsEventWriteInt64(mDelegate->mEvent, 2));
		EXPECT_CALL(*mDelegate, statsEventWriteInt32(mDelegate->mEvent, DISPLAY_EVENT_CONNECTIONS));
		EXPECT_CALL(*mDelegate,
		statsEventWriteByteArray(mDelegate->mEvent,
		BytesEq((const uint8_t*)expectedFrameDuration.c_str(),
		expectedFrameDuration.size()),
		expectedFrameDuration.size()));
		EXPECT_CALL(*mDelegate,
		statsEventWriteByteArray(mDelegate->mEvent,
		BytesEq((const uint8_t*)
		expectedRenderEngineTiming.c_str(),
		expectedRenderEngineTiming.size()),
		expectedRenderEngineTiming.size()));
		EXPECT_CALL(*mDelegate, statsEventBuild(mDelegate->mEvent));
		}
		EXPECT_EQ(AStatsManager_PULL_SUCCESS,
		@@ -854,49 +914,6 @@ TEST_F(TimeStatsTest, globalStatsCallback) {
		EXPECT_EQ(0, globalProto.present_to_present_size());
		}

		namespace {
		std::string buildExpectedHistogramBytestring(const std::vector<int32_t>& times,
		const std::vector<int32_t>& frameCounts) {
		util::ProtoOutputStream proto;
		for (int i = 0; i < times.size(); i++) {
		ALOGE("Writing time: %d", times[i]);
		proto.write(util::FIELD_TYPE_INT32 \| util::FIELD_COUNT_REPEATED \| 1 /* field id */,
		(int32_t)times[i]);
		ALOGE("Writing count: %d", frameCounts[i]);
		proto.write(util::FIELD_TYPE_INT64 \| util::FIELD_COUNT_REPEATED \| 2 /* field id */,
		(int64_t)frameCounts[i]);
		}
		std::string byteString;
		proto.serializeToString(&byteString);
		return byteString;
		}

		std::string dumpByteStringHex(const std::string& str) {
		std::stringstream ss;
		ss << std::hex;
		for (const char& c : str) {
		ss << (int)c << " ";
		}

		return ss.str();
		}

		} // namespace

		MATCHER_P2(BytesEq, bytes, size, "") {
		std::string expected;
		expected.append((const char*)bytes, size);
		std::string actual;
		actual.append((const char*)arg, size);

		*result_listener << "Bytes are not equal! \n";
		*result_listener << "size: " << size << "\n";
		*result_listener << "expected: " << dumpByteStringHex(expected).c_str() << "\n";
		*result_listener << "actual: " << dumpByteStringHex(actual).c_str() << "\n";

		return expected == actual;
		}

		TEST_F(TimeStatsTest, layerStatsCallback_pullsAllAndClears) {
		constexpr size_t LATE_ACQUIRE_FRAMES = 2;
		constexpr size_t BAD_DESIRED_PRESENT_FRAMES = 3;