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