Merge "SF Timestats: add new metrics" (d544a9c2) · Commits · e / os / platform_frameworks_native

services/surfaceflinger/TimeStats/TimeStats.cpp

+11 −4

Original line number	Diff line number	Diff line
		@@ -178,10 +178,17 @@ void TimeStats::flushAvailableRecordsToStatsLocked(const std::string& layerName)
		if (!timeStats.stats.count(layerName)) {
		timeStats.stats[layerName].layerName = layerName;
		timeStats.stats[layerName].packageName = getPackageName(layerName);
		timeStats.stats[layerName].statsStart = static_cast<int64_t>(std::time(0));
		}
		TimeStatsHelper::TimeStatsLayer& timeStatsLayer = timeStats.stats[layerName];
		timeStatsLayer.totalFrames++;
		timeStatsLayer.droppedFrames += layerRecord.droppedFrames;
		layerRecord.droppedFrames = 0;

		const int32_t postToAcquireMs = msBetween(timeRecords[0].frameTime.postTime,
		timeRecords[0].frameTime.acquireTime);
		ALOGV("[%s]-[%" PRIu64 "]-post2acquire[%d]", layerName.c_str(),
		timeRecords[0].frameTime.frameNumber, postToAcquireMs);
		timeStatsLayer.deltas["post2acquire"].insert(postToAcquireMs);

		const int32_t postToPresentMs = msBetween(timeRecords[0].frameTime.postTime,
		timeRecords[0].frameTime.presentTime);
		@@ -212,8 +219,6 @@ void TimeStats::flushAvailableRecordsToStatsLocked(const std::string& layerName)
		ALOGV("[%s]-[%" PRIu64 "]-present2present[%d]", layerName.c_str(),
		timeRecords[0].frameTime.frameNumber, presentToPresentMs);
		timeStatsLayer.deltas["present2present"].insert(presentToPresentMs);

		timeStats.stats[layerName].statsEnd = static_cast<int64_t>(std::time(0));
		}
		prevTimeRecord = timeRecords[0];
		timeRecords.pop_front();
		@@ -403,6 +408,7 @@ void TimeStats::clearLayerRecord(const std::string& layerName) {
		layerRecord.timeRecords.clear();
		layerRecord.prevTimeRecord.ready = false;
		layerRecord.waitData = -1;
		layerRecord.droppedFrames = 0;
		}

		void TimeStats::removeTimeRecord(const std::string& layerName, uint64_t frameNumber) {
		@@ -422,8 +428,9 @@ void TimeStats::removeTimeRecord(const std::string& layerName, uint64_t frameNum
		if (removeAt == layerRecord.timeRecords.size()) return;
		layerRecord.timeRecords.erase(layerRecord.timeRecords.begin() + removeAt);
		if (layerRecord.waitData > static_cast<int32_t>(removeAt)) {
		--layerRecord.waitData;
		layerRecord.waitData--;
		}
		layerRecord.droppedFrames++;
		}

		void TimeStats::enable() {

services/surfaceflinger/TimeStats/TimeStats.h

+4 −0

Original line number	Diff line number	Diff line
		@@ -61,6 +61,7 @@ class TimeStats {
		// specific frame are still not fully received. This is not waiting for
		// fences to signal, but rather waiting to receive those fences/timestamps.
		int32_t waitData = -1;
		uint32_t droppedFrames = 0;
		TimeRecord prevTimeRecord;
		std::deque<TimeRecord> timeRecords;
		};
		@@ -81,8 +82,11 @@ public:
		void setPresentTime(const std::string& layerName, uint64_t frameNumber, nsecs_t presentTime);
		void setPresentFence(const std::string& layerName, uint64_t frameNumber,
		const std::shared_ptr<FenceTime>& presentFence);
		// On producer disconnect with BufferQueue.
		void onDisconnect(const std::string& layerName);
		// When SF is cleaning up the queue, clear the LayerRecord as well.
		void clearLayerRecord(const std::string& layerName);
		// If SF skips or rejects a buffer, remove the corresponding TimeRecord.
		void removeTimeRecord(const std::string& layerName, uint64_t frameNumber);

		private:

services/surfaceflinger/TimeStats/timestatsproto/TimeStatsHelper.cpp

+8 −11

Original line number	Diff line number	Diff line
		@@ -68,12 +68,11 @@ std::string TimeStatsHelper::Histogram::toString() const {
		}

		std::string TimeStatsHelper::TimeStatsLayer::toString() const {
		std::string result = "";
		std::string result = "\n";
		StringAppendF(&result, "layerName = %s\n", layerName.c_str());
		StringAppendF(&result, "packageName = %s\n", packageName.c_str());
		StringAppendF(&result, "statsStart = %lld\n", static_cast<long long int>(statsStart));
		StringAppendF(&result, "statsEnd = %lld\n", static_cast<long long int>(statsEnd));
		StringAppendF(&result, "totalFrames = %d\n", totalFrames);
		StringAppendF(&result, "droppedFrames = %d\n", droppedFrames);
		auto iter = deltas.find("present2present");
		if (iter != deltas.end()) {
		StringAppendF(&result, "averageFPS = %.3f\n", 1000.0 / iter->second.averageTime());
		@@ -93,7 +92,6 @@ std::string TimeStatsHelper::TimeStatsGlobal::toString(std::optional<uint32_t> m
		StringAppendF(&result, "totalFrames = %d\n", totalFrames);
		StringAppendF(&result, "missedFrames = %d\n", missedFrames);
		StringAppendF(&result, "clientCompositionFrames = %d\n", clientCompositionFrames);
		StringAppendF(&result, "TimeStats for each layer is as below:\n");
		const auto dumpStats = generateDumpStats(maxLayers);
		for (auto& ele : dumpStats) {
		StringAppendF(&result, "%s", ele->toString().c_str());
		@@ -106,15 +104,14 @@ SFTimeStatsLayerProto TimeStatsHelper::TimeStatsLayer::toProto() const {
		SFTimeStatsLayerProto layerProto;
		layerProto.set_layer_name(layerName);
		layerProto.set_package_name(packageName);
		layerProto.set_stats_start(statsStart);
		layerProto.set_stats_end(statsEnd);
		layerProto.set_total_frames(totalFrames);
		layerProto.set_dropped_frames(droppedFrames);
		for (auto& ele : deltas) {
		SFTimeStatsDeltaProto* deltaProto = layerProto.add_deltas();
		deltaProto->set_delta_name(ele.first);
		for (auto& histEle : ele.second.hist) {
		SFTimeStatsHistogramBucketProto* histProto = deltaProto->add_histograms();
		histProto->set_render_millis(histEle.first);
		histProto->set_time_millis(histEle.first);
		histProto->set_frame_count(histEle.second);
		}
		}

services/surfaceflinger/TimeStats/timestatsproto/include/timestatsproto/TimeStatsHelper.h

+1 −2

Original line number	Diff line number	Diff line
		@@ -42,9 +42,8 @@ public:
		public:
		std::string layerName;
		std::string packageName;
		int64_t statsStart = 0;
		int64_t statsEnd = 0;
		int32_t totalFrames = 0;
		int32_t droppedFrames = 0;
		std::unordered_map<std::string, Histogram> deltas;

		std::string toString() const;

services/surfaceflinger/TimeStats/timestatsproto/timestats.proto

+26 −13

Original line number	Diff line number	Diff line
		@@ -20,46 +20,59 @@ package android.surfaceflinger;

		option optimize_for = LITE_RUNTIME;

		// //depot/google3/java/com/google/android/apps/graphics/proto/timestats.proto
		// is based on this proto. Please only make valid protobuf changes to these
		// messages, and keep the other file in sync per Android release. Please also
		// do not include "option optimize_for = LITE_RUNTIME;" on google3 side.

		// Next tag: 7
		message SFTimeStatsGlobalProto {
		// The start & end timestamps in UTC as
		// milliseconds since January 1, 1970
		// The stats start time in UTC as seconds since January 1, 1970
		optional int64 stats_start = 1;
		// The stats end time in UTC as seconds since January 1, 1970
		optional int64 stats_end = 2;
		// Total frames
		// Total number of frames presented during tracing period.
		optional int32 total_frames = 3;
		// Total missed frames of SurfaceFlinger.
		optional int32 missed_frames = 4;
		// Total frames fallback to client composition.
		optional int32 client_composition_frames = 5;

		// Stats per layer. Apps could have multiple layers.
		repeated SFTimeStatsLayerProto stats = 6;
		}

		// Next tag: 8
		message SFTimeStatsLayerProto {
		// The layer name
		// The name of the visible view layer.
		optional string layer_name = 1;
		// The package name
		// The package name of the application owning this layer.
		optional string package_name = 2;
		// The start & end timestamps in UTC as
		// milliseconds since January 1, 1970
		// The stats start time in UTC as seconds since January 1, 1970
		optional int64 stats_start = 3;
		// The stats end time in UTC as seconds since January 1, 1970
		optional int64 stats_end = 4;
		// Distinct frame count.
		// Total number of frames presented during tracing period.
		optional int32 total_frames = 5;

		// Total number of frames dropped by SurfaceFlinger.
		optional int32 dropped_frames = 7;
		// There are multiple timestamps tracked in SurfaceFlinger, and these are the
		// histograms of deltas between different combinations of those timestamps.
		repeated SFTimeStatsDeltaProto deltas = 6;
		}

		// Next tag: 3
		message SFTimeStatsDeltaProto {
		// Name of the time interval
		optional string delta_name = 1;
		// Histogram of the delta time
		// Histogram of the delta time. There should be at most 85 buckets ranging
		// from [0ms, 1ms) to [1000ms, infinity)
		repeated SFTimeStatsHistogramBucketProto histograms = 2;
		}

		// Next tag: 3
		message SFTimeStatsHistogramBucketProto {
		// Lower bound of render time in milliseconds.
		optional int32 render_millis = 1;
		// Lower bound of time interval in milliseconds.
		optional int32 time_millis = 1;
		// Number of frames in the bucket.
		optional int32 frame_count = 2;
		}