Merge "SF: add trace points for dispatcher system" (abd1a135) · Commits · e / os / platform_frameworks_native

services/surfaceflinger/Scheduler/SchedulerUtils.h

+8 −0

Original line number	Diff line number	Diff line
		@@ -16,6 +16,7 @@

		#pragma once

		#include <utils/Timers.h>
		#include <cinttypes>
		#include <numeric>
		#include <unordered_map>
		@@ -70,6 +71,13 @@ auto calculate_mode(const T& v) {
		return static_cast<int>(std::max_element(counts.begin(), counts.end(), compareCounts)->first);
		}

		template <class T, size_t N>
		constexpr size_t arrayLen(T (&)[N]) {
		return N;
		}

		static constexpr size_t max64print = std::numeric_limits<nsecs_t>::digits10 + 1;

		} // namespace android::scheduler

		namespace std {

services/surfaceflinger/Scheduler/Timer.cpp

+1 −10

Original line number	Diff line number	Diff line
		@@ -25,6 +25,7 @@
		#include <chrono>
		#include <cstdint>

		#include "SchedulerUtils.h"
		#include "Timer.h"

		namespace android::scheduler {
		@@ -32,11 +33,6 @@ namespace android::scheduler {
		static constexpr size_t kReadPipe = 0;
		static constexpr size_t kWritePipe = 1;

		template <class T, size_t N>
		constexpr size_t arrayLen(T (&)[N]) {
		return N;
		}

		Timer::Timer()
		: mTimerFd(timerfd_create(CLOCK_MONOTONIC, TFD_CLOEXEC \| TFD_NONBLOCK)),
		mEpollFd(epoll_create1(EPOLL_CLOEXEC)) {
		@@ -66,11 +62,8 @@ nsecs_t Timer::now() const {
		return systemTime(SYSTEM_TIME_MONOTONIC);
		}

		constexpr char const* timerTraceTag = "AlarmInNs";
		void Timer::alarmIn(std::function<void()> const& cb, nsecs_t fireIn) {
		std::lock_guard<decltype(mMutex)> lk(mMutex);
		ATRACE_INT64(timerTraceTag, fireIn);

		using namespace std::literals;
		static constexpr int ns_per_s =
		std::chrono::duration_cast<std::chrono::nanoseconds>(1s).count();
		@@ -91,7 +84,6 @@ void Timer::alarmIn(std::function<void()> const& cb, nsecs_t fireIn) {

		void Timer::alarmCancel() {
		std::lock_guard<decltype(mMutex)> lk(mMutex);
		ATRACE_INT64(timerTraceTag, 0);

		struct itimerspec old_timer;
		struct itimerspec new_timer {
		@@ -137,7 +129,6 @@ void Timer::dispatch() {

		uint64_t iteration = 0;
		char const traceNamePrefix[] = "TimerIteration #";
		static constexpr size_t max64print = std::numeric_limits<decltype(iteration)>::digits10;
		static constexpr size_t maxlen = arrayLen(traceNamePrefix) + max64print;
		std::array<char, maxlen> str_buffer;
		auto timing = true;

services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp

+25 −0

Original line number	Diff line number	Diff line
		@@ -52,6 +52,13 @@ std::optional<nsecs_t> VSyncDispatchTimerQueueEntry::wakeupTime() const {
		return {mArmedInfo->mActualWakeupTime};
		}

		std::optional<nsecs_t> VSyncDispatchTimerQueueEntry::targetVsync() const {
		if (!mArmedInfo) {
		return {};
		}
		return {mArmedInfo->mActualVsyncTime};
		}

		ScheduleResult VSyncDispatchTimerQueueEntry::schedule(nsecs_t workDuration, nsecs_t earliestVsync,
		VSyncTracker& tracker, nsecs_t now) {
		auto nextVsyncTime =
		@@ -143,9 +150,21 @@ void VSyncDispatchTimerQueue::rearmTimer(nsecs_t now) {
		rearmTimerSkippingUpdateFor(now, mCallbacks.end());
		}

		void VSyncDispatchTimerQueue::TraceBuffer::note(std::string_view name, nsecs_t alarmIn,
		nsecs_t vsFor) {
		if (ATRACE_ENABLED()) {
		snprintf(str_buffer.data(), str_buffer.size(), "%.4s%s%" PRId64 "%s%" PRId64,
		name.substr(0, kMaxNamePrint).data(), kTraceNamePrefix, alarmIn,
		kTraceNameSeparator, vsFor);
		}
		ATRACE_NAME(str_buffer.data());
		}

		void VSyncDispatchTimerQueue::rearmTimerSkippingUpdateFor(
		nsecs_t now, CallbackMap::iterator const& skipUpdateIt) {
		std::optional<nsecs_t> min;
		std::optional<nsecs_t> targetVsync;
		std::optional<std::string_view> nextWakeupName;
		for (auto it = mCallbacks.begin(); it != mCallbacks.end(); it++) {
		auto& callback = it->second;
		if (!callback->wakeupTime()) {
		@@ -157,13 +176,19 @@ void VSyncDispatchTimerQueue::rearmTimerSkippingUpdateFor(
		}
		auto const wakeupTime = *callback->wakeupTime();
		if (!min \|\| (min && *min > wakeupTime)) {
		nextWakeupName = callback->name();
		min = wakeupTime;
		targetVsync = callback->targetVsync();
		}
		}

		if (min && (min < mIntendedWakeupTime)) {
		if (targetVsync && nextWakeupName) {
		mTraceBuffer.note(nextWakeupName, min - now, *targetVsync - now);
		}
		setTimer(*min, now);
		} else {
		ATRACE_NAME("cancel timer");
		cancelTimer();
		}
		}

services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.h

+15 −0

Original line number	Diff line number	Diff line
		@@ -17,6 +17,7 @@
		#pragma once

		#include <android-base/thread_annotations.h>
		#include <array>
		#include <functional>
		#include <memory>
		#include <mutex>
		@@ -24,6 +25,7 @@
		#include <string_view>
		#include <unordered_map>

		#include "SchedulerUtils.h"
		#include "VSyncDispatch.h"

		namespace android::scheduler {
		@@ -54,6 +56,8 @@ public:
		// It will not update the wakeupTime.
		std::optional<nsecs_t> wakeupTime() const;

		std::optional<nsecs_t> targetVsync() const;

		// This moves state from armed->disarmed.
		void disarm();

		@@ -134,6 +138,17 @@ private:

		CallbackMap mCallbacks GUARDED_BY(mMutex);
		nsecs_t mIntendedWakeupTime GUARDED_BY(mMutex) = kInvalidTime;

		struct TraceBuffer {
		static constexpr char const kTraceNamePrefix[] = "-alarm in:";
		static constexpr char const kTraceNameSeparator[] = " for vs:";
		static constexpr size_t kMaxNamePrint = 4;
		static constexpr size_t kNumTsPrinted = 2;
		static constexpr size_t maxlen = kMaxNamePrint + arrayLen(kTraceNamePrefix) +
		arrayLen(kTraceNameSeparator) - 1 + (kNumTsPrinted * max64print);
		std::array<char, maxlen> str_buffer;
		void note(std::string_view name, nsecs_t in, nsecs_t vs);
		} mTraceBuffer GUARDED_BY(mMutex);
		};

		} // namespace android::scheduler

services/surfaceflinger/Scheduler/VSyncPredictor.cpp

+22 −5

Original line number	Diff line number	Diff line
		@@ -23,28 +23,35 @@
		#include "VSyncPredictor.h"
		#include <android-base/logging.h>
		#include <cutils/compiler.h>
		#include <cutils/properties.h>
		#include <utils/Log.h>
		#include <utils/Trace.h>
		#include <algorithm>
		#include <chrono>
		#include <sstream>
		#include "SchedulerUtils.h"

		namespace android::scheduler {
		static auto constexpr kNeedsSamplesTag = "SamplesRequested";

		static auto constexpr kMaxPercent = 100u;

		VSyncPredictor::~VSyncPredictor() = default;

		VSyncPredictor::VSyncPredictor(nsecs_t idealPeriod, size_t historySize,
		size_t minimumSamplesForPrediction, uint32_t outlierTolerancePercent)
		: kHistorySize(historySize),
		: mTraceOn(property_get_bool("debug.sf.vsp_trace", false)),
		kHistorySize(historySize),
		kMinimumSamplesForPrediction(minimumSamplesForPrediction),
		kOutlierTolerancePercent(std::min(outlierTolerancePercent, kMaxPercent)),
		mIdealPeriod(idealPeriod) {
		resetModel();
		}

		inline void VSyncPredictor::traceInt64If(const char* name, int64_t value) const {
		if (CC_UNLIKELY(mTraceOn)) {
		ATRACE_INT64(name, value);
		}
		}

		inline size_t VSyncPredictor::next(int i) const {
		return (i + 1) % timestamps.size();
		}
		@@ -68,7 +75,7 @@ void VSyncPredictor::addVsyncTimestamp(nsecs_t timestamp) {
		std::lock_guard<std::mutex> lk(mMutex);

		if (!validate(timestamp)) {
		ALOGW("timestamp was too far off the last known timestamp");
		ALOGV("timestamp was too far off the last known timestamp");
		return;
		}

		@@ -114,6 +121,8 @@ void VSyncPredictor::addVsyncTimestamp(nsecs_t timestamp) {
		static constexpr int kScalingFactor = 10;

		for (auto i = 0u; i < timestamps.size(); i++) {
		traceInt64If("VSP-ts", timestamps[i]);

		vsyncTS[i] = timestamps[i] - oldest_ts;
		ordinals[i] = ((vsyncTS[i] + (currentPeriod / 2)) / currentPeriod) * kScalingFactor;
		}
		@@ -140,6 +149,9 @@ void VSyncPredictor::addVsyncTimestamp(nsecs_t timestamp) {
		nsecs_t const anticipatedPeriod = top / bottom * kScalingFactor;
		nsecs_t const intercept = meanTS - (anticipatedPeriod * meanOrdinal / kScalingFactor);

		traceInt64If("VSP-period", anticipatedPeriod);
		traceInt64If("VSP-intercept", intercept);

		it->second = {anticipatedPeriod, intercept};

		ALOGV("model update ts: %" PRId64 " slope: %" PRId64 " intercept: %" PRId64, timestamp,
		@@ -152,6 +164,7 @@ nsecs_t VSyncPredictor::nextAnticipatedVSyncTimeFrom(nsecs_t timePoint) const {
		auto const [slope, intercept] = getVSyncPredictionModel(lk);

		if (timestamps.empty()) {
		traceInt64If("VSP-mode", 1);
		auto const knownTimestamp = mKnownTimestamp ? *mKnownTimestamp : timePoint;
		auto const numPeriodsOut = ((timePoint - knownTimestamp) / mIdealPeriod) + 1;
		return knownTimestamp + numPeriodsOut * mIdealPeriod;
		@@ -164,6 +177,10 @@ nsecs_t VSyncPredictor::nextAnticipatedVSyncTimeFrom(nsecs_t timePoint) const {
		auto const ordinalRequest = (timePoint - zeroPoint + slope) / slope;
		auto const prediction = (ordinalRequest * slope) + intercept + oldest;

		traceInt64If("VSP-mode", 0);
		traceInt64If("VSP-timePoint", timePoint);
		traceInt64If("VSP-prediction", prediction);

		auto const printer = [&, slope = slope, intercept = intercept] {
		std::stringstream str;
		str << "prediction made from: " << timePoint << "prediction: " << prediction << " (+"
		@@ -227,7 +244,7 @@ bool VSyncPredictor::needsMoreSamples(nsecs_t now) const {
		}
		}

		ATRACE_INT(kNeedsSamplesTag, needsMoreSamples);
		ATRACE_INT("VSP-moreSamples", needsMoreSamples);
		return needsMoreSamples;
		}