Create a wrapper for atrace macros
Create a SF specific macro to call into atrace. This will make the
switch to perfetto for capturing atrace tags easier.
Flag: EXEMPT refactor
Bug: 349905670
Test: perfetto
Change-Id: I4d046d837f52ef78b08e3c97556f2eddb06232dd
diff --git a/services/surfaceflinger/Scheduler/EventThread.cpp b/services/surfaceflinger/Scheduler/EventThread.cpp
index 6b65449..d31fcea 100644
--- a/services/surfaceflinger/Scheduler/EventThread.cpp
+++ b/services/surfaceflinger/Scheduler/EventThread.cpp
@@ -33,7 +33,7 @@
#include <android-base/stringprintf.h>
#include <binder/IPCThreadState.h>
-
+#include <common/trace.h>
#include <cutils/compiler.h>
#include <cutils/sched_policy.h>
@@ -41,7 +41,6 @@
#include <gui/SchedulingPolicy.h>
#include <utils/Errors.h>
-#include <utils/Trace.h>
#include <common/FlagManager.h>
#include <scheduler/VsyncConfig.h>
@@ -226,14 +225,14 @@
}
binder::Status EventThreadConnection::requestNextVsync() {
- ATRACE_CALL();
+ SFTRACE_CALL();
mEventThread->requestNextVsync(sp<EventThreadConnection>::fromExisting(this));
return binder::Status::ok();
}
binder::Status EventThreadConnection::getLatestVsyncEventData(
ParcelableVsyncEventData* outVsyncEventData) {
- ATRACE_CALL();
+ SFTRACE_CALL();
outVsyncEventData->vsync =
mEventThread->getLatestVsyncEventData(sp<EventThreadConnection>::fromExisting(this),
systemTime());
diff --git a/services/surfaceflinger/Scheduler/LayerHistory.cpp b/services/surfaceflinger/Scheduler/LayerHistory.cpp
index a819b79..4fd4c0e 100644
--- a/services/surfaceflinger/Scheduler/LayerHistory.cpp
+++ b/services/surfaceflinger/Scheduler/LayerHistory.cpp
@@ -21,8 +21,8 @@
#include "LayerHistory.h"
#include <android-base/stringprintf.h>
+#include <common/trace.h>
#include <cutils/properties.h>
-#include <gui/TraceUtils.h>
#include <utils/Log.h>
#include <utils/Timers.h>
@@ -72,7 +72,7 @@
void trace(const LayerInfo& info, LayerHistory::LayerVoteType type, int fps) {
const auto traceType = [&](LayerHistory::LayerVoteType checkedType, int value) {
- ATRACE_INT(info.getTraceTag(checkedType), type == checkedType ? value : 0);
+ SFTRACE_INT(info.getTraceTag(checkedType), type == checkedType ? value : 0);
};
traceType(LayerHistory::LayerVoteType::NoVote, 1);
@@ -190,7 +190,7 @@
}
auto LayerHistory::summarize(const RefreshRateSelector& selector, nsecs_t now) -> Summary {
- ATRACE_CALL();
+ SFTRACE_CALL();
Summary summary;
std::lock_guard lock(mLock);
@@ -204,7 +204,7 @@
ALOGV("%s has priority: %d %s focused", info->getName().c_str(), frameRateSelectionPriority,
layerFocused ? "" : "not");
- ATRACE_FORMAT("%s", info->getName().c_str());
+ SFTRACE_FORMAT("%s", info->getName().c_str());
const auto votes = info->getRefreshRateVote(selector, now);
for (LayerInfo::LayerVote vote : votes) {
if (vote.isNoVote()) {
@@ -222,8 +222,8 @@
const std::string categoryString = vote.category == FrameRateCategory::Default
? ""
: base::StringPrintf("category=%s", ftl::enum_string(vote.category).c_str());
- ATRACE_FORMAT_INSTANT("%s %s %s (%.2f)", ftl::enum_string(vote.type).c_str(),
- to_string(vote.fps).c_str(), categoryString.c_str(), weight);
+ SFTRACE_FORMAT_INSTANT("%s %s %s (%.2f)", ftl::enum_string(vote.type).c_str(),
+ to_string(vote.fps).c_str(), categoryString.c_str(), weight);
summary.push_back({info->getName(), info->getOwnerUid(), vote.type, vote.fps,
vote.seamlessness, vote.category, vote.categorySmoothSwitchOnly,
weight, layerFocused});
@@ -238,7 +238,7 @@
}
void LayerHistory::partitionLayers(nsecs_t now, bool isVrrDevice) {
- ATRACE_CALL();
+ SFTRACE_CALL();
const nsecs_t threshold = getActiveLayerThreshold(now);
// iterate over inactive map
@@ -310,7 +310,7 @@
if (gameModeFrameRateOverride.isValid()) {
info->setLayerVote({gameFrameRateOverrideVoteType, gameModeFrameRateOverride});
- ATRACE_FORMAT_INSTANT("GameModeFrameRateOverride");
+ SFTRACE_FORMAT_INSTANT("GameModeFrameRateOverride");
if (CC_UNLIKELY(mTraceEnabled)) {
trace(*info, gameFrameRateOverrideVoteType,
gameModeFrameRateOverride.getIntValue());
@@ -326,19 +326,19 @@
} else if (gameDefaultFrameRateOverride.isValid()) {
info->setLayerVote(
{gameFrameRateOverrideVoteType, gameDefaultFrameRateOverride});
- ATRACE_FORMAT_INSTANT("GameDefaultFrameRateOverride");
+ SFTRACE_FORMAT_INSTANT("GameDefaultFrameRateOverride");
if (CC_UNLIKELY(mTraceEnabled)) {
trace(*info, gameFrameRateOverrideVoteType,
gameDefaultFrameRateOverride.getIntValue());
}
} else {
if (frameRate.isValid() && !frameRate.isVoteValidForMrr(isVrrDevice)) {
- ATRACE_FORMAT_INSTANT("Reset layer to ignore explicit vote on MRR %s: %s "
- "%s %s",
- info->getName().c_str(),
- ftl::enum_string(frameRate.vote.type).c_str(),
- to_string(frameRate.vote.rate).c_str(),
- ftl::enum_string(frameRate.category).c_str());
+ SFTRACE_FORMAT_INSTANT("Reset layer to ignore explicit vote on MRR %s: %s "
+ "%s %s",
+ info->getName().c_str(),
+ ftl::enum_string(frameRate.vote.type).c_str(),
+ to_string(frameRate.vote.rate).c_str(),
+ ftl::enum_string(frameRate.category).c_str());
}
info->resetLayerVote();
}
@@ -349,12 +349,12 @@
frameRate.vote.seamlessness, frameRate.category});
} else {
if (!frameRate.isVoteValidForMrr(isVrrDevice)) {
- ATRACE_FORMAT_INSTANT("Reset layer to ignore explicit vote on MRR %s: %s "
- "%s %s",
- info->getName().c_str(),
- ftl::enum_string(frameRate.vote.type).c_str(),
- to_string(frameRate.vote.rate).c_str(),
- ftl::enum_string(frameRate.category).c_str());
+ SFTRACE_FORMAT_INSTANT("Reset layer to ignore explicit vote on MRR %s: %s "
+ "%s %s",
+ info->getName().c_str(),
+ ftl::enum_string(frameRate.vote.type).c_str(),
+ to_string(frameRate.vote.rate).c_str(),
+ ftl::enum_string(frameRate.category).c_str());
}
info->resetLayerVote();
}
@@ -421,7 +421,7 @@
bool LayerHistory::isSmallDirtyArea(uint32_t dirtyArea, float threshold) const {
const float ratio = (float)dirtyArea / mDisplayArea;
const bool isSmallDirty = ratio <= threshold;
- ATRACE_FORMAT_INSTANT("small dirty=%s, ratio=%.3f", isSmallDirty ? "true" : "false", ratio);
+ SFTRACE_FORMAT_INSTANT("small dirty=%s, ratio=%.3f", isSmallDirty ? "true" : "false", ratio);
return isSmallDirty;
}
diff --git a/services/surfaceflinger/Scheduler/LayerInfo.cpp b/services/surfaceflinger/Scheduler/LayerInfo.cpp
index 632f42a..a1a60e3 100644
--- a/services/surfaceflinger/Scheduler/LayerInfo.cpp
+++ b/services/surfaceflinger/Scheduler/LayerInfo.cpp
@@ -27,10 +27,10 @@
#include <utility>
#include <android/native_window.h>
+#include <common/trace.h>
#include <cutils/compiler.h>
#include <cutils/trace.h>
#include <ftl/enum.h>
-#include <gui/TraceUtils.h>
#include <system/window.h>
#undef LOG_TAG
@@ -259,7 +259,7 @@
}
if (smallDirtyCount > 0) {
- ATRACE_FORMAT_INSTANT("small dirty = %" PRIu32, smallDirtyCount);
+ SFTRACE_FORMAT_INSTANT("small dirty = %" PRIu32, smallDirtyCount);
}
if (numDeltas == 0) {
@@ -272,7 +272,7 @@
std::optional<Fps> LayerInfo::calculateRefreshRateIfPossible(const RefreshRateSelector& selector,
nsecs_t now) {
- ATRACE_CALL();
+ SFTRACE_CALL();
static constexpr float MARGIN = 1.0f; // 1Hz
if (!hasEnoughDataForHeuristic()) {
ALOGV("Not enough data");
@@ -307,7 +307,7 @@
LayerInfo::RefreshRateVotes LayerInfo::getRefreshRateVote(const RefreshRateSelector& selector,
nsecs_t now) {
- ATRACE_CALL();
+ SFTRACE_CALL();
LayerInfo::RefreshRateVotes votes;
if (mLayerVote.type != LayerHistory::LayerVoteType::Heuristic) {
@@ -315,8 +315,8 @@
const auto voteType = mLayerVote.type == LayerHistory::LayerVoteType::NoVote
? LayerHistory::LayerVoteType::NoVote
: LayerHistory::LayerVoteType::ExplicitCategory;
- ATRACE_FORMAT_INSTANT("Vote %s (category=%s)", ftl::enum_string(voteType).c_str(),
- ftl::enum_string(mLayerVote.category).c_str());
+ SFTRACE_FORMAT_INSTANT("Vote %s (category=%s)", ftl::enum_string(voteType).c_str(),
+ ftl::enum_string(mLayerVote.category).c_str());
ALOGV("%s voted %s with category: %s", mName.c_str(),
ftl::enum_string(voteType).c_str(),
ftl::enum_string(mLayerVote.category).c_str());
@@ -326,7 +326,7 @@
if (mLayerVote.fps.isValid() ||
mLayerVote.type != LayerHistory::LayerVoteType::ExplicitDefault) {
- ATRACE_FORMAT_INSTANT("Vote %s", ftl::enum_string(mLayerVote.type).c_str());
+ SFTRACE_FORMAT_INSTANT("Vote %s", ftl::enum_string(mLayerVote.type).c_str());
ALOGV("%s voted %d", mName.c_str(), static_cast<int>(mLayerVote.type));
votes.push_back({mLayerVote.type, mLayerVote.fps, mLayerVote.seamlessness,
FrameRateCategory::Default, mLayerVote.categorySmoothSwitchOnly});
@@ -336,7 +336,7 @@
}
if (isAnimating(now)) {
- ATRACE_FORMAT_INSTANT("animating");
+ SFTRACE_FORMAT_INSTANT("animating");
ALOGV("%s is animating", mName.c_str());
mLastRefreshRate.animating = true;
votes.push_back({LayerHistory::LayerVoteType::Max, Fps()});
@@ -345,7 +345,7 @@
// Vote for max refresh rate whenever we're front-buffered.
if (FlagManager::getInstance().vrr_config() && isFrontBuffered()) {
- ATRACE_FORMAT_INSTANT("front buffered");
+ SFTRACE_FORMAT_INSTANT("front buffered");
ALOGV("%s is front-buffered", mName.c_str());
votes.push_back({LayerHistory::LayerVoteType::Max, Fps()});
return votes;
@@ -354,7 +354,7 @@
const LayerInfo::Frequent frequent = isFrequent(now);
mIsFrequencyConclusive = frequent.isConclusive;
if (!frequent.isFrequent) {
- ATRACE_FORMAT_INSTANT("infrequent");
+ SFTRACE_FORMAT_INSTANT("infrequent");
ALOGV("%s is infrequent", mName.c_str());
mLastRefreshRate.infrequent = true;
mLastSmallDirtyCount = 0;
@@ -365,14 +365,14 @@
}
if (frequent.clearHistory) {
- ATRACE_FORMAT_INSTANT("frequent.clearHistory");
+ SFTRACE_FORMAT_INSTANT("frequent.clearHistory");
ALOGV("%s frequent.clearHistory", mName.c_str());
clearHistory(now);
}
// Return no vote if the recent frames are small dirty.
if (frequent.isSmallDirty && !mLastRefreshRate.reported.isValid()) {
- ATRACE_FORMAT_INSTANT("NoVote (small dirty)");
+ SFTRACE_FORMAT_INSTANT("NoVote (small dirty)");
ALOGV("%s is small dirty", mName.c_str());
votes.push_back({LayerHistory::LayerVoteType::NoVote, Fps()});
return votes;
@@ -380,13 +380,13 @@
auto refreshRate = calculateRefreshRateIfPossible(selector, now);
if (refreshRate.has_value()) {
- ATRACE_FORMAT_INSTANT("calculated (%s)", to_string(*refreshRate).c_str());
+ SFTRACE_FORMAT_INSTANT("calculated (%s)", to_string(*refreshRate).c_str());
ALOGV("%s calculated refresh rate: %s", mName.c_str(), to_string(*refreshRate).c_str());
votes.push_back({LayerHistory::LayerVoteType::Heuristic, refreshRate.value()});
return votes;
}
- ATRACE_FORMAT_INSTANT("Max (can't resolve refresh rate)");
+ SFTRACE_FORMAT_INSTANT("Max (can't resolve refresh rate)");
ALOGV("%s Max (can't resolve refresh rate)", mName.c_str());
votes.push_back({LayerHistory::LayerVoteType::Max, Fps()});
return votes;
@@ -452,7 +452,7 @@
mHeuristicTraceTagData = makeHeuristicTraceTagData();
}
- ATRACE_INT(mHeuristicTraceTagData->average.c_str(), refreshRate.getIntValue());
+ SFTRACE_INT(mHeuristicTraceTagData->average.c_str(), refreshRate.getIntValue());
}
return selectRefreshRate(selector);
@@ -486,9 +486,9 @@
mHeuristicTraceTagData = makeHeuristicTraceTagData();
}
- ATRACE_INT(mHeuristicTraceTagData->max.c_str(), max->refreshRate.getIntValue());
- ATRACE_INT(mHeuristicTraceTagData->min.c_str(), min->refreshRate.getIntValue());
- ATRACE_INT(mHeuristicTraceTagData->consistent.c_str(), consistent);
+ SFTRACE_INT(mHeuristicTraceTagData->max.c_str(), max->refreshRate.getIntValue());
+ SFTRACE_INT(mHeuristicTraceTagData->min.c_str(), min->refreshRate.getIntValue());
+ SFTRACE_INT(mHeuristicTraceTagData->consistent.c_str(), consistent);
}
return consistent ? maxClosestRate : Fps();
diff --git a/services/surfaceflinger/Scheduler/MessageQueue.cpp b/services/surfaceflinger/Scheduler/MessageQueue.cpp
index ff88d71..6a67ac5 100644
--- a/services/surfaceflinger/Scheduler/MessageQueue.cpp
+++ b/services/surfaceflinger/Scheduler/MessageQueue.cpp
@@ -57,7 +57,7 @@
mHandler(std::move(handler)) {}
void MessageQueue::vsyncCallback(nsecs_t vsyncTime, nsecs_t targetWakeupTime, nsecs_t readyTime) {
- ATRACE_CALL();
+ SFTRACE_CALL();
// Trace VSYNC-sf
mVsync.value = (mVsync.value + 1) % 2;
@@ -136,7 +136,7 @@
}
void MessageQueue::setDuration(std::chrono::nanoseconds workDuration) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::lock_guard lock(mVsync.mutex);
mVsync.workDuration = workDuration;
mVsync.scheduledFrameTimeOpt =
@@ -189,7 +189,7 @@
}
void MessageQueue::scheduleFrame() {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::lock_guard lock(mVsync.mutex);
mVsync.scheduledFrameTimeOpt =
diff --git a/services/surfaceflinger/Scheduler/RefreshRateSelector.cpp b/services/surfaceflinger/Scheduler/RefreshRateSelector.cpp
index be5ffbc..0b17c84 100644
--- a/services/surfaceflinger/Scheduler/RefreshRateSelector.cpp
+++ b/services/surfaceflinger/Scheduler/RefreshRateSelector.cpp
@@ -28,13 +28,12 @@
#include <android-base/properties.h>
#include <android-base/stringprintf.h>
+#include <common/trace.h>
#include <ftl/enum.h>
#include <ftl/fake_guard.h>
#include <ftl/match.h>
#include <ftl/unit.h>
-#include <gui/TraceUtils.h>
#include <scheduler/FrameRateMode.h>
-#include <utils/Trace.h>
#include "RefreshRateSelector.h"
@@ -494,7 +493,7 @@
GlobalSignals signals, Fps pacesetterFps) const
-> RankedFrameRates {
using namespace fps_approx_ops;
- ATRACE_CALL();
+ SFTRACE_CALL();
ALOGV("%s: %zu layers", __func__, layers.size());
const auto& activeMode = *getActiveModeLocked().modePtr;
@@ -508,8 +507,8 @@
});
if (!ranking.empty()) {
- ATRACE_FORMAT_INSTANT("%s (Follower display)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Follower display)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, kNoSignals, pacesetterFps};
}
@@ -521,8 +520,8 @@
if (signals.powerOnImminent) {
ALOGV("Power On Imminent");
const auto ranking = rankFrameRates(activeMode.getGroup(), RefreshRateOrder::Descending);
- ATRACE_FORMAT_INSTANT("%s (Power On Imminent)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Power On Imminent)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, GlobalSignals{.powerOnImminent = true}};
}
@@ -608,8 +607,8 @@
if (signals.touch && !hasExplicitVoteLayers) {
ALOGV("Touch Boost");
const auto ranking = rankFrameRates(anchorGroup, RefreshRateOrder::Descending);
- ATRACE_FORMAT_INSTANT("%s (Touch Boost)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Touch Boost)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, GlobalSignals{.touch = true}};
}
@@ -620,15 +619,15 @@
!(policy->primaryRangeIsSingleRate() && hasExplicitVoteLayers)) {
ALOGV("Idle");
const auto ranking = rankFrameRates(activeMode.getGroup(), RefreshRateOrder::Ascending);
- ATRACE_FORMAT_INSTANT("%s (Idle)", to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Idle)", to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, GlobalSignals{.idle = true}};
}
if (layers.empty() || noVoteLayers == layers.size()) {
ALOGV("No layers with votes");
const auto ranking = rankFrameRates(anchorGroup, RefreshRateOrder::Descending);
- ATRACE_FORMAT_INSTANT("%s (No layers with votes)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (No layers with votes)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, kNoSignals};
}
@@ -637,8 +636,8 @@
ALOGV("All layers NoPreference");
const auto ascendingWithPreferred =
rankFrameRates(anchorGroup, RefreshRateOrder::Ascending, activeMode.getId());
- ATRACE_FORMAT_INSTANT("%s (All layers NoPreference)",
- to_string(ascendingWithPreferred.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (All layers NoPreference)",
+ to_string(ascendingWithPreferred.front().frameRateMode.fps).c_str());
return {ascendingWithPreferred, kNoSignals};
}
@@ -653,8 +652,8 @@
return !smoothSwitchOnly ||
mode.modePtr->getId() == activeModeId;
});
- ATRACE_FORMAT_INSTANT("%s (All layers Min)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (All layers Min)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, kNoSignals};
}
@@ -847,13 +846,13 @@
if (noLayerScore) {
ALOGV("Layers not scored");
const auto descending = rankFrameRates(anchorGroup, RefreshRateOrder::Descending);
- ATRACE_FORMAT_INSTANT("%s (Layers not scored)",
- to_string(descending.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Layers not scored)",
+ to_string(descending.front().frameRateMode.fps).c_str());
return {descending, kNoSignals};
} else {
ALOGV("primaryRangeIsSingleRate");
- ATRACE_FORMAT_INSTANT("%s (primaryRangeIsSingleRate)",
- to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (primaryRangeIsSingleRate)",
+ to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, kNoSignals};
}
}
@@ -889,8 +888,8 @@
if (scores.front().frameRateMode.fps < touchRefreshRates.front().frameRateMode.fps) {
ALOGV("Touch Boost");
- ATRACE_FORMAT_INSTANT("%s (Touch Boost [late])",
- to_string(touchRefreshRates.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (Touch Boost [late])",
+ to_string(touchRefreshRates.front().frameRateMode.fps).c_str());
return {touchRefreshRates, GlobalSignals{.touch = true}};
}
}
@@ -901,13 +900,13 @@
ALOGV("preferredDisplayMode");
const auto ascendingWithPreferred =
rankFrameRates(anchorGroup, RefreshRateOrder::Ascending, activeMode.getId());
- ATRACE_FORMAT_INSTANT("%s (preferredDisplayMode)",
- to_string(ascendingWithPreferred.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (preferredDisplayMode)",
+ to_string(ascendingWithPreferred.front().frameRateMode.fps).c_str());
return {ascendingWithPreferred, kNoSignals};
}
ALOGV("%s (scored)", to_string(ranking.front().frameRateMode.fps).c_str());
- ATRACE_FORMAT_INSTANT("%s (scored)", to_string(ranking.front().frameRateMode.fps).c_str());
+ SFTRACE_FORMAT_INSTANT("%s (scored)", to_string(ranking.front().frameRateMode.fps).c_str());
return {ranking, kNoSignals};
}
@@ -949,7 +948,7 @@
Fps displayRefreshRate,
GlobalSignals globalSignals) const
-> UidToFrameRateOverride {
- ATRACE_CALL();
+ SFTRACE_CALL();
if (mConfig.enableFrameRateOverride == Config::FrameRateOverride::Disabled) {
return {};
}
@@ -1064,12 +1063,12 @@
return lhs < rhs && !ScoredFrameRate::scoresEqual(lhs, rhs);
});
ALOGV("%s: overriding to %s for uid=%d", __func__, to_string(overrideFps).c_str(), uid);
- ATRACE_FORMAT_INSTANT("%s: overriding to %s for uid=%d", __func__,
- to_string(overrideFps).c_str(), uid);
+ SFTRACE_FORMAT_INSTANT("%s: overriding to %s for uid=%d", __func__,
+ to_string(overrideFps).c_str(), uid);
if (ATRACE_ENABLED() && FlagManager::getInstance().trace_frame_rate_override()) {
std::stringstream ss;
ss << "FrameRateOverride " << uid;
- ATRACE_INT(ss.str().c_str(), overrideFps.getIntValue());
+ SFTRACE_INT(ss.str().c_str(), overrideFps.getIntValue());
}
frameRateOverrides.emplace(uid, overrideFps);
}
diff --git a/services/surfaceflinger/Scheduler/Scheduler.cpp b/services/surfaceflinger/Scheduler/Scheduler.cpp
index e669261..c43e942 100644
--- a/services/surfaceflinger/Scheduler/Scheduler.cpp
+++ b/services/surfaceflinger/Scheduler/Scheduler.cpp
@@ -24,12 +24,12 @@
#include <android-base/stringprintf.h>
#include <android/hardware/configstore/1.0/ISurfaceFlingerConfigs.h>
#include <android/hardware/configstore/1.1/ISurfaceFlingerConfigs.h>
+#include <common/trace.h>
#include <configstore/Utils.h>
#include <ftl/concat.h>
#include <ftl/enum.h>
#include <ftl/fake_guard.h>
#include <ftl/small_map.h>
-#include <gui/TraceUtils.h>
#include <gui/WindowInfo.h>
#include <system/window.h>
#include <ui/DisplayMap.h>
@@ -250,8 +250,8 @@
const auto period = pacesetterPtr->targeterPtr->target().expectedFrameDuration();
const auto skipDuration = Duration::fromNs(
static_cast<nsecs_t>(period.ns() * mPacesetterFrameDurationFractionToSkip));
- ATRACE_FORMAT("Injecting jank for %f%% of the frame (%" PRId64 " ns)",
- mPacesetterFrameDurationFractionToSkip * 100, skipDuration.ns());
+ SFTRACE_FORMAT("Injecting jank for %f%% of the frame (%" PRId64 " ns)",
+ mPacesetterFrameDurationFractionToSkip * 100, skipDuration.ns());
std::this_thread::sleep_for(skipDuration);
mPacesetterFrameDurationFractionToSkip = 0.f;
}
@@ -282,7 +282,7 @@
return true;
}
- ATRACE_FORMAT("%s uid: %d frameRate: %s", __func__, uid, to_string(*frameRate).c_str());
+ SFTRACE_FORMAT("%s uid: %d frameRate: %s", __func__, uid, to_string(*frameRate).c_str());
return getVsyncSchedule()->getTracker().isVSyncInPhase(expectedVsyncTime.ns(), *frameRate);
}
@@ -510,7 +510,7 @@
}
void Scheduler::resyncAllToHardwareVsync(bool allowToEnable) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::scoped_lock lock(mDisplayLock);
ftl::FakeGuard guard(kMainThreadContext);
@@ -544,12 +544,12 @@
void Scheduler::onHardwareVsyncRequest(PhysicalDisplayId id, bool enabled) {
static const auto& whence = __func__;
- ATRACE_NAME(ftl::Concat(whence, ' ', id.value, ' ', enabled).c_str());
+ SFTRACE_NAME(ftl::Concat(whence, ' ', id.value, ' ', enabled).c_str());
// On main thread to serialize reads/writes of pending hardware VSYNC state.
static_cast<void>(
schedule([=, this]() FTL_FAKE_GUARD(mDisplayLock) FTL_FAKE_GUARD(kMainThreadContext) {
- ATRACE_NAME(ftl::Concat(whence, ' ', id.value, ' ', enabled).c_str());
+ SFTRACE_NAME(ftl::Concat(whence, ' ', id.value, ' ', enabled).c_str());
if (const auto displayOpt = mDisplays.get(id)) {
auto& display = displayOpt->get();
@@ -631,7 +631,7 @@
}
void Scheduler::addPresentFence(PhysicalDisplayId id, std::shared_ptr<FenceTime> fence) {
- ATRACE_NAME(ftl::Concat(__func__, ' ', id.value).c_str());
+ SFTRACE_NAME(ftl::Concat(__func__, ' ', id.value).c_str());
const auto scheduleOpt =
(ftl::FakeGuard(mDisplayLock), mDisplays.get(id)).and_then([](const Display& display) {
return display.powerMode == hal::PowerMode::OFF
@@ -694,7 +694,7 @@
const auto selectorPtr = pacesetterSelectorPtr();
if (!selectorPtr->canSwitch()) return;
- ATRACE_CALL();
+ SFTRACE_CALL();
LayerHistory::Summary summary = mLayerHistory.summarize(*selectorPtr, systemTime());
applyPolicy(&Policy::contentRequirements, std::move(summary));
@@ -779,7 +779,7 @@
}
void Scheduler::kernelIdleTimerCallback(TimerState state) {
- ATRACE_INT("ExpiredKernelIdleTimer", static_cast<int>(state));
+ SFTRACE_INT("ExpiredKernelIdleTimer", static_cast<int>(state));
// TODO(145561154): cleanup the kernel idle timer implementation and the refresh rate
// magic number
@@ -810,7 +810,7 @@
void Scheduler::idleTimerCallback(TimerState state) {
applyPolicy(&Policy::idleTimer, state);
- ATRACE_INT("ExpiredIdleTimer", static_cast<int>(state));
+ SFTRACE_INT("ExpiredIdleTimer", static_cast<int>(state));
}
void Scheduler::touchTimerCallback(TimerState state) {
@@ -822,12 +822,12 @@
if (applyPolicy(&Policy::touch, touch).touch) {
mLayerHistory.clear();
}
- ATRACE_INT("TouchState", static_cast<int>(touch));
+ SFTRACE_INT("TouchState", static_cast<int>(touch));
}
void Scheduler::displayPowerTimerCallback(TimerState state) {
applyPolicy(&Policy::displayPowerTimer, state);
- ATRACE_INT("ExpiredDisplayPowerTimer", static_cast<int>(state));
+ SFTRACE_INT("ExpiredDisplayPowerTimer", static_cast<int>(state));
}
void Scheduler::dump(utils::Dumper& dumper) const {
@@ -990,7 +990,7 @@
auto& layerChoreographers = choreographers->second;
layerChoreographers.frameRate = fps;
- ATRACE_FORMAT_INSTANT("%s: %s for %s", __func__, to_string(fps).c_str(), layer.name.c_str());
+ SFTRACE_FORMAT_INSTANT("%s: %s for %s", __func__, to_string(fps).c_str(), layer.name.c_str());
ALOGV("%s: %s for %s", __func__, to_string(fps).c_str(), layer.name.c_str());
auto it = layerChoreographers.connections.begin();
@@ -1072,13 +1072,13 @@
void Scheduler::updateAttachedChoreographers(
const surfaceflinger::frontend::LayerHierarchy& layerHierarchy, Fps displayRefreshRate) {
- ATRACE_CALL();
+ SFTRACE_CALL();
updateAttachedChoreographersInternal(layerHierarchy, displayRefreshRate, 0);
}
template <typename S, typename T>
auto Scheduler::applyPolicy(S Policy::*statePtr, T&& newState) -> GlobalSignals {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::vector<display::DisplayModeRequest> modeRequests;
GlobalSignals consideredSignals;
@@ -1149,7 +1149,7 @@
}
auto Scheduler::chooseDisplayModes() const -> DisplayModeChoiceMap {
- ATRACE_CALL();
+ SFTRACE_CALL();
DisplayModeChoiceMap modeChoices;
const auto globalSignals = makeGlobalSignals();
diff --git a/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp b/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp
index 6d6b70d..8dae3ca 100644
--- a/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp
+++ b/services/surfaceflinger/Scheduler/VSyncDispatchTimerQueue.cpp
@@ -19,8 +19,8 @@
#include <vector>
#include <android-base/stringprintf.h>
+#include <common/trace.h>
#include <ftl/concat.h>
-#include <gui/TraceUtils.h>
#include <log/log_main.h>
#include <scheduler/TimeKeeper.h>
@@ -52,7 +52,7 @@
ftl::Concat trace(ftl::truncated<5>(entry.name()), " alarm in ",
ns2us(*entry.wakeupTime() - now), "us; VSYNC in ",
ns2us(*entry.targetVsync() - now), "us");
- ATRACE_FORMAT_INSTANT(trace.c_str());
+ SFTRACE_FORMAT_INSTANT(trace.c_str());
}
} // namespace
@@ -98,7 +98,7 @@
ScheduleResult VSyncDispatchTimerQueueEntry::schedule(VSyncDispatch::ScheduleTiming timing,
VSyncTracker& tracker, nsecs_t now) {
- ATRACE_NAME("VSyncDispatchTimerQueueEntry::schedule");
+ SFTRACE_NAME("VSyncDispatchTimerQueueEntry::schedule");
auto nextVsyncTime =
tracker.nextAnticipatedVSyncTimeFrom(std::max(timing.lastVsync,
now + timing.workDuration +
@@ -110,8 +110,8 @@
mArmedInfo && (nextVsyncTime > (mArmedInfo->mActualVsyncTime + mMinVsyncDistance));
bool const wouldSkipAWakeup =
mArmedInfo && ((nextWakeupTime > (mArmedInfo->mActualWakeupTime + mMinVsyncDistance)));
- ATRACE_FORMAT_INSTANT("%s: wouldSkipAVsyncTarget=%d wouldSkipAWakeup=%d", mName.c_str(),
- wouldSkipAVsyncTarget, wouldSkipAWakeup);
+ SFTRACE_FORMAT_INSTANT("%s: wouldSkipAVsyncTarget=%d wouldSkipAWakeup=%d", mName.c_str(),
+ wouldSkipAVsyncTarget, wouldSkipAWakeup);
if (FlagManager::getInstance().dont_skip_on_early_ro()) {
if (wouldSkipAVsyncTarget || wouldSkipAWakeup) {
nextVsyncTime = mArmedInfo->mActualVsyncTime;
@@ -154,13 +154,13 @@
bool const nextVsyncTooClose = mLastDispatchTime &&
(nextVsyncTime - *mLastDispatchTime + mMinVsyncDistance) <= currentPeriod;
if (alreadyDispatchedForVsync) {
- ATRACE_FORMAT_INSTANT("alreadyDispatchedForVsync");
+ SFTRACE_FORMAT_INSTANT("alreadyDispatchedForVsync");
return tracker.nextAnticipatedVSyncTimeFrom(*mLastDispatchTime + mMinVsyncDistance,
*mLastDispatchTime);
}
if (nextVsyncTooClose) {
- ATRACE_FORMAT_INSTANT("nextVsyncTooClose");
+ SFTRACE_FORMAT_INSTANT("nextVsyncTooClose");
return tracker.nextAnticipatedVSyncTimeFrom(*mLastDispatchTime + currentPeriod,
*mLastDispatchTime + currentPeriod);
}
@@ -172,7 +172,7 @@
VSyncDispatch::ScheduleTiming timing,
std::optional<ArmingInfo> armedInfo) const
-> ArmingInfo {
- ATRACE_NAME("VSyncDispatchTimerQueueEntry::getArmedInfo");
+ SFTRACE_NAME("VSyncDispatchTimerQueueEntry::getArmedInfo");
const auto earliestReadyBy = now + timing.workDuration + timing.readyDuration;
const auto earliestVsync = std::max(earliestReadyBy, timing.lastVsync);
@@ -188,8 +188,8 @@
armedInfo && (nextVsyncTime > (armedInfo->mActualVsyncTime + mMinVsyncDistance));
bool const wouldSkipAWakeup =
armedInfo && (nextWakeupTime > (armedInfo->mActualWakeupTime + mMinVsyncDistance));
- ATRACE_FORMAT_INSTANT("%s: wouldSkipAVsyncTarget=%d wouldSkipAWakeup=%d", mName.c_str(),
- wouldSkipAVsyncTarget, wouldSkipAWakeup);
+ SFTRACE_FORMAT_INSTANT("%s: wouldSkipAVsyncTarget=%d wouldSkipAWakeup=%d", mName.c_str(),
+ wouldSkipAVsyncTarget, wouldSkipAWakeup);
if (wouldSkipAVsyncTarget || wouldSkipAWakeup) {
return *armedInfo;
}
@@ -199,7 +199,7 @@
}
void VSyncDispatchTimerQueueEntry::update(VSyncTracker& tracker, nsecs_t now) {
- ATRACE_NAME("VSyncDispatchTimerQueueEntry::update");
+ SFTRACE_NAME("VSyncDispatchTimerQueueEntry::update");
if (!mArmedInfo && !mWorkloadUpdateInfo) {
return;
}
@@ -208,9 +208,9 @@
const auto workDelta = mWorkloadUpdateInfo->workDuration - mScheduleTiming.workDuration;
const auto readyDelta = mWorkloadUpdateInfo->readyDuration - mScheduleTiming.readyDuration;
const auto lastVsyncDelta = mWorkloadUpdateInfo->lastVsync - mScheduleTiming.lastVsync;
- ATRACE_FORMAT_INSTANT("Workload updated workDelta=%" PRId64 " readyDelta=%" PRId64
- " lastVsyncDelta=%" PRId64,
- workDelta, readyDelta, lastVsyncDelta);
+ SFTRACE_FORMAT_INSTANT("Workload updated workDelta=%" PRId64 " readyDelta=%" PRId64
+ " lastVsyncDelta=%" PRId64,
+ workDelta, readyDelta, lastVsyncDelta);
mScheduleTiming = *mWorkloadUpdateInfo;
mWorkloadUpdateInfo.reset();
}
@@ -310,7 +310,7 @@
void VSyncDispatchTimerQueue::rearmTimerSkippingUpdateFor(
nsecs_t now, CallbackMap::const_iterator skipUpdateIt) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::optional<nsecs_t> min;
std::optional<nsecs_t> targetVsync;
std::optional<std::string_view> nextWakeupName;
@@ -337,13 +337,13 @@
if (min && min < mIntendedWakeupTime) {
setTimer(*min, now);
} else {
- ATRACE_NAME("cancel timer");
+ SFTRACE_NAME("cancel timer");
cancelTimer();
}
}
void VSyncDispatchTimerQueue::timerCallback() {
- ATRACE_CALL();
+ SFTRACE_CALL();
struct Invocation {
std::shared_ptr<VSyncDispatchTimerQueueEntry> callback;
nsecs_t vsyncTimestamp;
@@ -383,7 +383,7 @@
for (auto const& invocation : invocations) {
ftl::Concat trace(ftl::truncated<5>(invocation.callback->name()));
- ATRACE_FORMAT("%s: %s", __func__, trace.c_str());
+ SFTRACE_FORMAT("%s: %s", __func__, trace.c_str());
invocation.callback->callback(invocation.vsyncTimestamp, invocation.wakeupTimestamp,
invocation.deadlineTimestamp);
}
diff --git a/services/surfaceflinger/Scheduler/VSyncPredictor.cpp b/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
index 0644aca..16799bd 100644
--- a/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
+++ b/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
@@ -30,10 +30,10 @@
#include <android-base/logging.h>
#include <android-base/stringprintf.h>
#include <common/FlagManager.h>
+#include <common/trace.h>
#include <cutils/compiler.h>
#include <cutils/properties.h>
#include <ftl/concat.h>
-#include <gui/TraceUtils.h>
#include <utils/Log.h>
#include "RefreshRateSelector.h"
@@ -77,7 +77,7 @@
}
inline void VSyncPredictor::traceInt64(const char* name, int64_t value) const {
- ATRACE_INT64(ftl::Concat(ftl::truncated<14>(name), " ", mId.value).c_str(), value);
+ SFTRACE_INT64(ftl::Concat(ftl::truncated<14>(name), " ", mId.value).c_str(), value);
}
inline size_t VSyncPredictor::next(size_t i) const {
@@ -98,7 +98,7 @@
(timestamp - aValidTimestamp) % idealPeriod() * kMaxPercent / idealPeriod();
if (percent >= kOutlierTolerancePercent &&
percent <= (kMaxPercent - kOutlierTolerancePercent)) {
- ATRACE_FORMAT_INSTANT("timestamp is not aligned with model");
+ SFTRACE_FORMAT_INSTANT("timestamp is not aligned with model");
return false;
}
@@ -109,7 +109,7 @@
const auto distancePercent = std::abs(*iter - timestamp) * kMaxPercent / idealPeriod();
if (distancePercent < kOutlierTolerancePercent) {
// duplicate timestamp
- ATRACE_FORMAT_INSTANT("duplicate timestamp");
+ SFTRACE_FORMAT_INSTANT("duplicate timestamp");
return false;
}
return true;
@@ -135,7 +135,7 @@
}
bool VSyncPredictor::addVsyncTimestamp(nsecs_t timestamp) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::lock_guard lock(mMutex);
@@ -155,8 +155,8 @@
} else {
mKnownTimestamp = timestamp;
}
- ATRACE_FORMAT_INSTANT("timestamp rejected. mKnownTimestamp was %.2fms ago",
- (mClock->now() - *mKnownTimestamp) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("timestamp rejected. mKnownTimestamp was %.2fms ago",
+ (mClock->now() - *mKnownTimestamp) / 1e6f);
return false;
}
@@ -297,7 +297,7 @@
nsecs_t VSyncPredictor::nextAnticipatedVSyncTimeFrom(nsecs_t timePoint,
std::optional<nsecs_t> lastVsyncOpt) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::lock_guard lock(mMutex);
const auto now = TimePoint::fromNs(mClock->now());
@@ -330,8 +330,8 @@
if (*vsyncOpt > mLastCommittedVsync) {
mLastCommittedVsync = *vsyncOpt;
- ATRACE_FORMAT_INSTANT("mLastCommittedVsync in %.2fms",
- float(mLastCommittedVsync.ns() - mClock->now()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("mLastCommittedVsync in %.2fms",
+ float(mLastCommittedVsync.ns() - mClock->now()) / 1e6f);
}
return vsyncOpt->ns();
@@ -374,7 +374,7 @@
}
void VSyncPredictor::setRenderRate(Fps renderRate, bool applyImmediately) {
- ATRACE_FORMAT("%s %s", __func__, to_string(renderRate).c_str());
+ SFTRACE_FORMAT("%s %s", __func__, to_string(renderRate).c_str());
ALOGV("%s %s: RenderRate %s ", __func__, to_string(mId).c_str(), to_string(renderRate).c_str());
std::lock_guard lock(mMutex);
const auto prevRenderRate = mRenderRateOpt;
@@ -382,7 +382,7 @@
const auto renderPeriodDelta =
prevRenderRate ? prevRenderRate->getPeriodNsecs() - renderRate.getPeriodNsecs() : 0;
if (applyImmediately) {
- ATRACE_FORMAT_INSTANT("applyImmediately");
+ SFTRACE_FORMAT_INSTANT("applyImmediately");
while (mTimelines.size() > 1) {
mTimelines.pop_front();
}
@@ -394,7 +394,7 @@
const bool newRenderRateIsHigher = renderPeriodDelta > renderRate.getPeriodNsecs() &&
mLastCommittedVsync.ns() - mClock->now() > 2 * renderRate.getPeriodNsecs();
if (newRenderRateIsHigher) {
- ATRACE_FORMAT_INSTANT("newRenderRateIsHigher");
+ SFTRACE_FORMAT_INSTANT("newRenderRateIsHigher");
mTimelines.clear();
mLastCommittedVsync = TimePoint::fromNs(0);
@@ -415,7 +415,7 @@
void VSyncPredictor::setDisplayModePtr(ftl::NonNull<DisplayModePtr> modePtr) {
LOG_ALWAYS_FATAL_IF(mId != modePtr->getPhysicalDisplayId(),
"mode does not belong to the display");
- ATRACE_FORMAT("%s %s", __func__, to_string(*modePtr).c_str());
+ SFTRACE_FORMAT("%s %s", __func__, to_string(*modePtr).c_str());
const auto timeout = modePtr->getVrrConfig()
? modePtr->getVrrConfig()->notifyExpectedPresentConfig
: std::nullopt;
@@ -443,7 +443,7 @@
Duration VSyncPredictor::ensureMinFrameDurationIsKept(TimePoint expectedPresentTime,
TimePoint lastConfirmedPresentTime) {
- ATRACE_CALL();
+ SFTRACE_CALL();
if (mNumVsyncsForFrame <= 1) {
return 0ns;
@@ -456,14 +456,15 @@
auto prev = lastConfirmedPresentTime.ns();
for (auto& current : mPastExpectedPresentTimes) {
if (CC_UNLIKELY(mTraceOn)) {
- ATRACE_FORMAT_INSTANT("current %.2f past last signaled fence",
- static_cast<float>(current.ns() - lastConfirmedPresentTime.ns()) /
- 1e6f);
+ SFTRACE_FORMAT_INSTANT("current %.2f past last signaled fence",
+ static_cast<float>(current.ns() -
+ lastConfirmedPresentTime.ns()) /
+ 1e6f);
}
const auto minPeriodViolation = current.ns() - prev + threshold < minFramePeriod;
if (minPeriodViolation) {
- ATRACE_NAME("minPeriodViolation");
+ SFTRACE_NAME("minPeriodViolation");
current = TimePoint::fromNs(prev + minFramePeriod);
prev = current.ns();
} else {
@@ -487,16 +488,16 @@
void VSyncPredictor::onFrameBegin(TimePoint expectedPresentTime,
TimePoint lastConfirmedPresentTime) {
- ATRACE_NAME("VSyncPredictor::onFrameBegin");
+ SFTRACE_NAME("VSyncPredictor::onFrameBegin");
std::lock_guard lock(mMutex);
if (!mDisplayModePtr->getVrrConfig()) return;
if (CC_UNLIKELY(mTraceOn)) {
- ATRACE_FORMAT_INSTANT("vsync is %.2f past last signaled fence",
- static_cast<float>(expectedPresentTime.ns() -
- lastConfirmedPresentTime.ns()) /
- 1e6f);
+ SFTRACE_FORMAT_INSTANT("vsync is %.2f past last signaled fence",
+ static_cast<float>(expectedPresentTime.ns() -
+ lastConfirmedPresentTime.ns()) /
+ 1e6f);
}
const auto currentPeriod = mRateMap.find(idealPeriod())->second.slope;
const auto threshold = currentPeriod / 2;
@@ -507,9 +508,9 @@
const bool frontIsBeforeConfirmed = front < lastConfirmedPresentTime.ns() + threshold;
if (frontIsBeforeConfirmed) {
if (CC_UNLIKELY(mTraceOn)) {
- ATRACE_FORMAT_INSTANT("Discarding old vsync - %.2f before last signaled fence",
- static_cast<float>(lastConfirmedPresentTime.ns() - front) /
- 1e6f);
+ SFTRACE_FORMAT_INSTANT("Discarding old vsync - %.2f before last signaled fence",
+ static_cast<float>(lastConfirmedPresentTime.ns() - front) /
+ 1e6f);
}
mPastExpectedPresentTimes.pop_front();
} else {
@@ -524,7 +525,7 @@
}
void VSyncPredictor::onFrameMissed(TimePoint expectedPresentTime) {
- ATRACE_NAME("VSyncPredictor::onFrameMissed");
+ SFTRACE_NAME("VSyncPredictor::onFrameMissed");
std::lock_guard lock(mMutex);
if (!mDisplayModePtr->getVrrConfig()) return;
@@ -550,7 +551,7 @@
}
void VSyncPredictor::clearTimestamps() {
- ATRACE_CALL();
+ SFTRACE_CALL();
if (!mTimestamps.empty()) {
auto const maxRb = *std::max_element(mTimestamps.begin(), mTimestamps.end());
@@ -612,7 +613,7 @@
if (mRenderRateOpt &&
mLastCommittedVsync.ns() + mRenderRateOpt->getPeriodNsecs() * kEnoughFramesToBreakPhase <
mClock->now()) {
- ATRACE_FORMAT_INSTANT("kEnoughFramesToBreakPhase");
+ SFTRACE_FORMAT_INSTANT("kEnoughFramesToBreakPhase");
mTimelines.clear();
mLastCommittedVsync = TimePoint::fromNs(0);
mTimelines.emplace_back(mLastCommittedVsync, mIdealPeriod, mRenderRateOpt);
@@ -648,16 +649,16 @@
void VSyncPredictor::VsyncTimeline::freeze(TimePoint lastVsync) {
LOG_ALWAYS_FATAL_IF(mValidUntil.has_value());
- ATRACE_FORMAT_INSTANT("renderRate %s valid for %.2f",
- mRenderRateOpt ? to_string(*mRenderRateOpt).c_str() : "NA",
- float(lastVsync.ns() - TimePoint::now().ns()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("renderRate %s valid for %.2f",
+ mRenderRateOpt ? to_string(*mRenderRateOpt).c_str() : "NA",
+ float(lastVsync.ns() - TimePoint::now().ns()) / 1e6f);
mValidUntil = lastVsync;
}
std::optional<TimePoint> VSyncPredictor::VsyncTimeline::nextAnticipatedVSyncTimeFrom(
Model model, std::optional<Period> minFramePeriodOpt, nsecs_t vsync,
MissedVsync missedVsync, std::optional<nsecs_t> lastVsyncOpt) {
- ATRACE_FORMAT("renderRate %s", mRenderRateOpt ? to_string(*mRenderRateOpt).c_str() : "NA");
+ SFTRACE_FORMAT("renderRate %s", mRenderRateOpt ? to_string(*mRenderRateOpt).c_str() : "NA");
nsecs_t vsyncTime = snapToVsyncAlignedWithRenderRate(model, vsync);
const auto threshold = model.slope / 2;
@@ -671,7 +672,7 @@
// on whether we skipped the frame (onFrameMissed) or not (onFrameBegin) we apply a
// different fixup. There is no need to to shift the vsync timeline again.
vsyncTime += missedVsync.fixup.ns();
- ATRACE_FORMAT_INSTANT("lastFrameMissed");
+ SFTRACE_FORMAT_INSTANT("lastFrameMissed");
} else if (mightBackpressure && lastVsyncOpt) {
if (!FlagManager::getInstance().vrr_bugfix_24q4()) {
// lastVsyncOpt does not need to be corrected with the new rate, and
@@ -682,27 +683,27 @@
const auto vsyncDiff = vsyncTime - *lastVsyncOpt;
if (vsyncDiff <= minFramePeriodOpt->ns() - threshold) {
// avoid a duplicate vsync
- ATRACE_FORMAT_INSTANT("skipping a vsync to avoid duplicate frame. next in %.2f "
- "which "
- "is %.2f "
- "from "
- "prev. "
- "adjust by %.2f",
- static_cast<float>(vsyncTime - TimePoint::now().ns()) / 1e6f,
- static_cast<float>(vsyncDiff) / 1e6f,
- static_cast<float>(mRenderRateOpt->getPeriodNsecs()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("skipping a vsync to avoid duplicate frame. next in %.2f "
+ "which "
+ "is %.2f "
+ "from "
+ "prev. "
+ "adjust by %.2f",
+ static_cast<float>(vsyncTime - TimePoint::now().ns()) / 1e6f,
+ static_cast<float>(vsyncDiff) / 1e6f,
+ static_cast<float>(mRenderRateOpt->getPeriodNsecs()) / 1e6f);
vsyncTime += mRenderRateOpt->getPeriodNsecs();
}
}
}
- ATRACE_FORMAT_INSTANT("vsync in %.2fms", float(vsyncTime - TimePoint::now().ns()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("vsync in %.2fms", float(vsyncTime - TimePoint::now().ns()) / 1e6f);
const bool isVsyncInvalid = FlagManager::getInstance().vrr_bugfix_24q4()
? isWithin(TimePoint::fromNs(vsyncTime)) == VsyncOnTimeline::Outside
: mValidUntil && vsyncTime > mValidUntil->ns();
if (isVsyncInvalid) {
- ATRACE_FORMAT_INSTANT("no longer valid for vsync in %.2f",
- static_cast<float>(vsyncTime - TimePoint::now().ns()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("no longer valid for vsync in %.2f",
+ static_cast<float>(vsyncTime - TimePoint::now().ns()) / 1e6f);
return std::nullopt;
}
@@ -766,14 +767,14 @@
return true;
}
const auto vsyncSequence = getVsyncSequenceLocked(model, vsync);
- ATRACE_FORMAT_INSTANT("vsync in: %.2f sequence: %" PRId64 " divisor: %zu",
- getVsyncIn(now, vsyncSequence.vsyncTime), vsyncSequence.seq, divisor);
+ SFTRACE_FORMAT_INSTANT("vsync in: %.2f sequence: %" PRId64 " divisor: %zu",
+ getVsyncIn(now, vsyncSequence.vsyncTime), vsyncSequence.seq, divisor);
return vsyncSequence.seq % divisor == 0;
}
void VSyncPredictor::VsyncTimeline::shiftVsyncSequence(Duration phase) {
if (mLastVsyncSequence) {
- ATRACE_FORMAT_INSTANT("adjusting vsync by %.2f", static_cast<float>(phase.ns()) / 1e6f);
+ SFTRACE_FORMAT_INSTANT("adjusting vsync by %.2f", static_cast<float>(phase.ns()) / 1e6f);
mLastVsyncSequence->vsyncTime += phase.ns();
}
}
diff --git a/services/surfaceflinger/Scheduler/VSyncReactor.cpp b/services/surfaceflinger/Scheduler/VSyncReactor.cpp
index 8038364..2455822 100644
--- a/services/surfaceflinger/Scheduler/VSyncReactor.cpp
+++ b/services/surfaceflinger/Scheduler/VSyncReactor.cpp
@@ -20,11 +20,10 @@
//#define LOG_NDEBUG 0
#include <assert.h>
+#include <common/trace.h>
#include <cutils/properties.h>
#include <ftl/concat.h>
-#include <gui/TraceUtils.h>
#include <log/log.h>
-#include <utils/Trace.h>
#include "../TracedOrdinal.h"
#include "VSyncDispatch.h"
@@ -53,7 +52,7 @@
VSyncReactor::~VSyncReactor() = default;
bool VSyncReactor::addPresentFence(std::shared_ptr<FenceTime> fence) {
- ATRACE_CALL();
+ SFTRACE_CALL();
if (!fence) {
return false;
@@ -66,8 +65,8 @@
std::lock_guard lock(mMutex);
if (mExternalIgnoreFences || mInternalIgnoreFences) {
- ATRACE_FORMAT_INSTANT("mExternalIgnoreFences=%d mInternalIgnoreFences=%d",
- mExternalIgnoreFences, mInternalIgnoreFences);
+ SFTRACE_FORMAT_INSTANT("mExternalIgnoreFences=%d mInternalIgnoreFences=%d",
+ mExternalIgnoreFences, mInternalIgnoreFences);
return true;
}
@@ -121,7 +120,7 @@
}
void VSyncReactor::startPeriodTransitionInternal(ftl::NonNull<DisplayModePtr> modePtr) {
- ATRACE_FORMAT("%s %" PRIu64, __func__, mId.value);
+ SFTRACE_FORMAT("%s %" PRIu64, __func__, mId.value);
mPeriodConfirmationInProgress = true;
mModePtrTransitioningTo = modePtr.get();
mMoreSamplesNeeded = true;
@@ -129,15 +128,15 @@
}
void VSyncReactor::endPeriodTransition() {
- ATRACE_FORMAT("%s %" PRIu64, __func__, mId.value);
+ SFTRACE_FORMAT("%s %" PRIu64, __func__, mId.value);
mModePtrTransitioningTo.reset();
mPeriodConfirmationInProgress = false;
mLastHwVsync.reset();
}
void VSyncReactor::onDisplayModeChanged(ftl::NonNull<DisplayModePtr> modePtr, bool force) {
- ATRACE_INT64(ftl::Concat("VSR-", __func__, " ", mId.value).c_str(),
- modePtr->getVsyncRate().getPeriodNsecs());
+ SFTRACE_INT64(ftl::Concat("VSR-", __func__, " ", mId.value).c_str(),
+ modePtr->getVsyncRate().getPeriodNsecs());
std::lock_guard lock(mMutex);
mLastHwVsync.reset();
@@ -191,7 +190,7 @@
std::lock_guard lock(mMutex);
if (periodConfirmed(timestamp, hwcVsyncPeriod)) {
- ATRACE_FORMAT("VSR %" PRIu64 ": period confirmed", mId.value);
+ SFTRACE_FORMAT("VSR %" PRIu64 ": period confirmed", mId.value);
if (mModePtrTransitioningTo) {
mTracker.setDisplayModePtr(ftl::as_non_null(mModePtrTransitioningTo));
*periodFlushed = true;
@@ -205,12 +204,12 @@
endPeriodTransition();
mMoreSamplesNeeded = mTracker.needsMoreSamples();
} else if (mPeriodConfirmationInProgress) {
- ATRACE_FORMAT("VSR %" PRIu64 ": still confirming period", mId.value);
+ SFTRACE_FORMAT("VSR %" PRIu64 ": still confirming period", mId.value);
mLastHwVsync = timestamp;
mMoreSamplesNeeded = true;
*periodFlushed = false;
} else {
- ATRACE_FORMAT("VSR %" PRIu64 ": adding sample", mId.value);
+ SFTRACE_FORMAT("VSR %" PRIu64 ": adding sample", mId.value);
*periodFlushed = false;
mTracker.addVsyncTimestamp(timestamp);
mMoreSamplesNeeded = mTracker.needsMoreSamples();
diff --git a/services/surfaceflinger/Scheduler/VsyncModulator.cpp b/services/surfaceflinger/Scheduler/VsyncModulator.cpp
index 586357f..fa377e9 100644
--- a/services/surfaceflinger/Scheduler/VsyncModulator.cpp
+++ b/services/surfaceflinger/Scheduler/VsyncModulator.cpp
@@ -22,8 +22,8 @@
#include "VsyncModulator.h"
#include <android-base/properties.h>
+#include <common/trace.h>
#include <log/log.h>
-#include <utils/Trace.h>
#include <chrono>
#include <cinttypes>
@@ -72,7 +72,7 @@
}
if (mTraceDetailedInfo) {
- ATRACE_INT("mEarlyWakeup", static_cast<int>(mEarlyWakeupRequests.size()));
+ SFTRACE_INT("mEarlyWakeup", static_cast<int>(mEarlyWakeupRequests.size()));
}
if (mEarlyWakeupRequests.empty() && schedule == Schedule::EarlyEnd) {
@@ -172,9 +172,9 @@
const bool isEarlyGpu = &offsets == &mVsyncConfigSet.earlyGpu;
const bool isLate = &offsets == &mVsyncConfigSet.late;
- ATRACE_INT("Vsync-EarlyOffsetsOn", isEarly);
- ATRACE_INT("Vsync-EarlyGpuOffsetsOn", isEarlyGpu);
- ATRACE_INT("Vsync-LateOffsetsOn", isLate);
+ SFTRACE_INT("Vsync-EarlyOffsetsOn", isEarly);
+ SFTRACE_INT("Vsync-EarlyGpuOffsetsOn", isEarlyGpu);
+ SFTRACE_INT("Vsync-LateOffsetsOn", isLate);
}
return offsets;
diff --git a/services/surfaceflinger/Scheduler/VsyncSchedule.cpp b/services/surfaceflinger/Scheduler/VsyncSchedule.cpp
index 2fa3318..d3e312a 100644
--- a/services/surfaceflinger/Scheduler/VsyncSchedule.cpp
+++ b/services/surfaceflinger/Scheduler/VsyncSchedule.cpp
@@ -18,8 +18,8 @@
#include <common/FlagManager.h>
+#include <common/trace.h>
#include <ftl/fake_guard.h>
-#include <gui/TraceUtils.h>
#include <scheduler/Fps.h>
#include <scheduler/Timer.h>
@@ -182,7 +182,7 @@
}
void VsyncSchedule::enableHardwareVsyncLocked() {
- ATRACE_CALL();
+ SFTRACE_CALL();
if (mHwVsyncState == HwVsyncState::Disabled) {
getTracker().resetModel();
mRequestHardwareVsync(mId, true);
@@ -191,7 +191,7 @@
}
void VsyncSchedule::disableHardwareVsync(bool disallow) {
- ATRACE_CALL();
+ SFTRACE_CALL();
std::lock_guard<std::mutex> lock(mHwVsyncLock);
switch (mHwVsyncState) {
case HwVsyncState::Enabled:
diff --git a/services/surfaceflinger/Scheduler/src/FrameTargeter.cpp b/services/surfaceflinger/Scheduler/src/FrameTargeter.cpp
index badd21e..60694b9 100644
--- a/services/surfaceflinger/Scheduler/src/FrameTargeter.cpp
+++ b/services/surfaceflinger/Scheduler/src/FrameTargeter.cpp
@@ -14,9 +14,8 @@
* limitations under the License.
*/
-#include <gui/TraceUtils.h>
-
#include <common/FlagManager.h>
+#include <common/trace.h>
#include <scheduler/FrameTargeter.h>
#include <scheduler/IVsyncSource.h>
@@ -90,9 +89,9 @@
mEarliestPresentTime = computeEarliestPresentTime(minFramePeriod, args.hwcMinWorkDuration);
}
- ATRACE_FORMAT("%s %" PRId64 " vsyncIn %.2fms%s", __func__, ftl::to_underlying(args.vsyncId),
- ticks<std::milli, float>(mExpectedPresentTime - TimePoint::now()),
- mExpectedPresentTime == args.expectedVsyncTime ? "" : " (adjusted)");
+ SFTRACE_FORMAT("%s %" PRId64 " vsyncIn %.2fms%s", __func__, ftl::to_underlying(args.vsyncId),
+ ticks<std::milli, float>(mExpectedPresentTime - TimePoint::now()),
+ mExpectedPresentTime == args.expectedVsyncTime ? "" : " (adjusted)");
const FenceTimePtr& pastPresentFence = presentFenceForPastVsync(minFramePeriod);
@@ -165,7 +164,7 @@
}
bool FrameTargeter::isFencePending(const FenceTimePtr& fence, int graceTimeMs) {
- ATRACE_CALL();
+ SFTRACE_CALL();
const status_t status = fence->wait(graceTimeMs);
// This is the same as Fence::Status::Unsignaled, but it saves a call to getStatus,
diff --git a/services/surfaceflinger/Scheduler/src/Timer.cpp b/services/surfaceflinger/Scheduler/src/Timer.cpp
index eeb9c60..fba3d58 100644
--- a/services/surfaceflinger/Scheduler/src/Timer.cpp
+++ b/services/surfaceflinger/Scheduler/src/Timer.cpp
@@ -24,10 +24,10 @@
#include <sys/timerfd.h>
#include <sys/unistd.h>
+#include <common/trace.h>
#include <ftl/concat.h>
#include <ftl/enum.h>
#include <log/log.h>
-#include <utils/Trace.h>
#include <scheduler/Timer.h>
@@ -190,7 +190,7 @@
setDebugState(DebugState::Running);
if (ATRACE_ENABLED()) {
ftl::Concat trace("TimerIteration #", iteration++);
- ATRACE_NAME(trace.c_str());
+ SFTRACE_NAME(trace.c_str());
}
if (nfds == -1) {