SF: use CLOCK_BOOTTIME for frame timeline
Using CLOCK_BOOTTIME avoids the need to resync CLOCK_MONOTONIC in
perfetto after suspend.
Bug: 185346474
Test: Collect perfetto traces and observe timeline slices
Change-Id: Ifda1fb43c6ac205ec60cb331c139e950a24a60cb
diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
index 81747d5..ec59888 100644
--- a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
+++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp
@@ -618,15 +618,15 @@
}
}
-void SurfaceFrame::tracePredictions(int64_t displayFrameToken) const {
+void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
// Expected timeline start
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
std::scoped_lock lock(mMutex);
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start();
@@ -644,8 +644,8 @@
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
std::scoped_lock lock(mMutex);
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* expectedSurfaceFrameEndEvent = event->set_frame_end();
@@ -654,14 +654,14 @@
});
}
-void SurfaceFrame::traceActuals(int64_t displayFrameToken) const {
+void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
// Actual timeline start
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
std::scoped_lock lock(mMutex);
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
// Actual start time is not yet available, so use expected start instead
if (mPredictionState == PredictionState::Expired) {
// If prediction is expired, we can't use the predicted start time. Instead, just use a
@@ -669,11 +669,12 @@
// frame in the trace.
nsecs_t endTime =
(mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime);
- packet->set_timestamp(
- static_cast<uint64_t>(endTime - kPredictionExpiredStartTimeDelta));
+ packet->set_timestamp(static_cast<uint64_t>(endTime - kPredictionExpiredStartTimeDelta +
+ monoBootOffset));
} else {
- packet->set_timestamp(static_cast<uint64_t>(
- mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime));
+ packet->set_timestamp(static_cast<uint64_t>(monoBootOffset + mActuals.startTime == 0
+ ? mPredictions.startTime
+ : mActuals.startTime));
}
auto* event = packet->set_frame_timeline_event();
@@ -706,11 +707,11 @@
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
std::scoped_lock lock(mMutex);
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
if (mPresentState == PresentState::Dropped) {
- packet->set_timestamp(static_cast<uint64_t>(mDropTime));
+ packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset));
} else {
- packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime));
+ packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset));
}
auto* event = packet->set_frame_timeline_event();
@@ -723,7 +724,7 @@
/**
* TODO(b/178637512): add inputEventId to the perfetto trace.
*/
-void SurfaceFrame::trace(int64_t displayFrameToken) const {
+void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset) const {
if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID ||
displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
// No packets can be traced with a missing token.
@@ -732,9 +733,9 @@
if (getPredictionState() != PredictionState::Expired) {
// Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in
// a trace.
- tracePredictions(displayFrameToken);
+ tracePredictions(displayFrameToken, monoBootOffset);
}
- traceActuals(displayFrameToken);
+ traceActuals(displayFrameToken, monoBootOffset);
}
namespace impl {
@@ -760,8 +761,9 @@
}
FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
- JankClassificationThresholds thresholds)
- : mMaxDisplayFrames(kDefaultMaxDisplayFrames),
+ JankClassificationThresholds thresholds, bool useBootTimeClock)
+ : mUseBootTimeClock(useBootTimeClock),
+ mMaxDisplayFrames(kDefaultMaxDisplayFrames),
mTimeStats(std::move(timeStats)),
mSurfaceFlingerPid(surfaceFlingerPid),
mJankClassificationThresholds(thresholds) {
@@ -1016,14 +1018,16 @@
}
}
-void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid) const {
+void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid,
+ nsecs_t monoBootOffset) const {
int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing();
// Expected timeline start
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(
+ static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start();
@@ -1037,8 +1041,9 @@
// Expected timeline end
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(
+ static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* expectedDisplayFrameEndEvent = event->set_frame_end();
@@ -1047,14 +1052,16 @@
});
}
-void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid) const {
+void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid,
+ nsecs_t monoBootOffset) const {
int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing();
// Actual timeline start
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.startTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(
+ static_cast<uint64_t>(mSurfaceFlingerActuals.startTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start();
@@ -1075,8 +1082,9 @@
// Actual timeline end
FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
- packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
- packet->set_timestamp(static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime));
+ packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
+ packet->set_timestamp(
+ static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime + monoBootOffset));
auto* event = packet->set_frame_timeline_event();
auto* actualDisplayFrameEndEvent = event->set_frame_end();
@@ -1085,7 +1093,7 @@
});
}
-void FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid) const {
+void FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const {
if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) {
// DisplayFrame should not have an invalid token.
ALOGE("Cannot trace DisplayFrame with invalid token");
@@ -1095,12 +1103,12 @@
if (mPredictionState == PredictionState::Valid) {
// Expired and unknown predictions have zeroed timestamps. This cannot be used in any
// meaningful way in a trace.
- tracePredictions(surfaceFlingerPid);
+ tracePredictions(surfaceFlingerPid, monoBootOffset);
}
- traceActuals(surfaceFlingerPid);
+ traceActuals(surfaceFlingerPid, monoBootOffset);
for (auto& surfaceFrame : mSurfaceFrames) {
- surfaceFrame->trace(mToken);
+ surfaceFrame->trace(mToken, monoBootOffset);
}
}
@@ -1164,6 +1172,12 @@
}
void FrameTimeline::flushPendingPresentFences() {
+ // Perfetto is using boottime clock to void drifts when the device goes
+ // to suspend.
+ const auto monoBootOffset = mUseBootTimeClock
+ ? (systemTime(SYSTEM_TIME_BOOTTIME) - systemTime(SYSTEM_TIME_MONOTONIC))
+ : 0;
+
for (size_t i = 0; i < mPendingPresentFences.size(); i++) {
const auto& pendingPresentFence = mPendingPresentFences[i];
nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
@@ -1175,7 +1189,7 @@
}
auto& displayFrame = pendingPresentFence.second;
displayFrame->onPresent(signalTime, mPreviousPresentTime);
- displayFrame->trace(mSurfaceFlingerPid);
+ displayFrame->trace(mSurfaceFlingerPid, monoBootOffset);
mPreviousPresentTime = signalTime;
mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i));
diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.h b/services/surfaceflinger/FrameTimeline/FrameTimeline.h
index 36d6290..a2305af 100644
--- a/services/surfaceflinger/FrameTimeline/FrameTimeline.h
+++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.h
@@ -204,8 +204,9 @@
std::string miniDump() const;
// Emits a packet for perfetto tracing. The function body will be executed only if tracing is
// enabled. The displayFrameToken is needed to link the SurfaceFrame to the corresponding
- // DisplayFrame at the trace processor side.
- void trace(int64_t displayFrameToken) const;
+ // DisplayFrame at the trace processor side. monoBootOffset is the difference
+ // between SYSTEM_TIME_BOOTTIME and SYSTEM_TIME_MONOTONIC.
+ void trace(int64_t displayFrameToken, nsecs_t monoBootOffset) const;
// Getter functions used only by FrameTimelineTests and SurfaceFrame internally
TimelineItem getActuals() const;
@@ -225,8 +226,8 @@
std::chrono::duration_cast<std::chrono::nanoseconds>(2ms).count();
private:
- void tracePredictions(int64_t displayFrameToken) const;
- void traceActuals(int64_t displayFrameToken) const;
+ void tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset) const;
+ void traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset) const;
void classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate,
nsecs_t& deadlineDelta) REQUIRES(mMutex);
@@ -369,8 +370,9 @@
// Dumpsys interface - dumps all data irrespective of jank
void dumpAll(std::string& result, nsecs_t baseTime) const;
// Emits a packet for perfetto tracing. The function body will be executed only if tracing
- // is enabled.
- void trace(pid_t surfaceFlingerPid) const;
+ // is enabled. monoBootOffset is the difference between SYSTEM_TIME_BOOTTIME
+ // and SYSTEM_TIME_MONOTONIC.
+ void trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const;
// Sets the token, vsyncPeriod, predictions and SF start time.
void onSfWakeUp(int64_t token, Fps refreshRate, std::optional<TimelineItem> predictions,
nsecs_t wakeUpTime);
@@ -401,8 +403,8 @@
private:
void dump(std::string& result, nsecs_t baseTime) const;
- void tracePredictions(pid_t surfaceFlingerPid) const;
- void traceActuals(pid_t surfaceFlingerPid) const;
+ void tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const;
+ void traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const;
void classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync,
nsecs_t previousPresentTime);
@@ -442,7 +444,7 @@
};
FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid,
- JankClassificationThresholds thresholds = {});
+ JankClassificationThresholds thresholds = {}, bool useBootTimeClock = true);
~FrameTimeline() = default;
frametimeline::TokenManager* getTokenManager() override { return &mTokenManager; }
@@ -484,6 +486,7 @@
TokenManager mTokenManager;
TraceCookieCounter mTraceCookieCounter;
mutable std::mutex mMutex;
+ const bool mUseBootTimeClock;
uint32_t mMaxDisplayFrames;
std::shared_ptr<TimeStats> mTimeStats;
const pid_t mSurfaceFlingerPid;
diff --git a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
index 834a560..f1efa92 100644
--- a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
+++ b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp
@@ -66,9 +66,10 @@
}
void SetUp() override {
+ constexpr bool kUseBootTimeClock = true;
mTimeStats = std::make_shared<mock::TimeStats>();
mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats, kSurfaceFlingerPid,
- kTestThresholds);
+ kTestThresholds, !kUseBootTimeClock);
mFrameTimeline->registerDataSource();
mTokenManager = &mFrameTimeline->mTokenManager;
mTraceCookieCounter = &mFrameTimeline->mTraceCookieCounter;