diff options
author | 2024-09-04 19:21:20 -0700 | |
---|---|---|
committer | 2024-09-13 01:14:57 +0000 | |
commit | 43a68c3fd6da28753a612965b4072ef93f9f888e (patch) | |
tree | b57673b69f19f6af8cdbba4b873d073ac0c43f6a | |
parent | 9a4c026c402afc2f49856ca6d01f8c6d50a9a56f (diff) |
SF: Do not trace FrameTimeline before start
Filter FrameTimeline events for frames started before the trace started.
Bug: 364194637
Test: manual
Flag: com.android.graphics.surfaceflinger.flags.filter_frames_before_trace_starts
Change-Id: I9185f384f306eddab1afc2ea9d7901dd70d2f1a2
6 files changed, 209 insertions, 104 deletions
diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp index 2311360ce9..47b811b721 100644 --- a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp +++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp @@ -38,6 +38,8 @@ using base::StringAppendF; using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent; using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource; +namespace { + void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals, const std::string& indent, PredictionState predictionState, nsecs_t baseTime) { StringAppendF(&result, "%s", indent.c_str()); @@ -319,6 +321,16 @@ nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions, return minTime; } +bool shouldTraceForDataSource(const FrameTimelineDataSource::TraceContext& ctx, nsecs_t timestamp) { + if (auto ds = ctx.GetDataSourceLocked(); ds && ds->getStartTime() > timestamp) { + return false; + } + + return true; +} + +} // namespace + int64_t TraceCookieCounter::getCookieForTracing() { return ++mTraceCookie; } @@ -726,15 +738,24 @@ void SurfaceFrame::onCommitNotComposited(Fps refreshRate, Fps displayFrameRender classifyJankLocked(JankType::None, refreshRate, displayFrameRenderRate, nullptr); } -void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset) const { +void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const { int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing(); + bool traced = false; // Expected timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + const auto timestamp = mPredictions.startTime; + if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) { + // Do not trace packets started before tracing starts. + return; + } + traced = true; + std::scoped_lock lock(mMutex); auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp(static_cast<uint64_t>(mPredictions.startTime + monoBootOffset)); + packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); auto* event = packet->set_frame_timeline_event(); auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start(); @@ -748,42 +769,54 @@ void SurfaceFrame::tracePredictions(int64_t displayFrameToken, nsecs_t monoBootO expectedSurfaceFrameStartEvent->set_layer_name(mDebugName); }); - // Expected timeline end - FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { - std::scoped_lock lock(mMutex); - auto packet = ctx.NewTracePacket(); - packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp(static_cast<uint64_t>(mPredictions.endTime + monoBootOffset)); + if (traced) { + // Expected timeline end + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + std::scoped_lock lock(mMutex); + auto packet = ctx.NewTracePacket(); + 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(); + auto* event = packet->set_frame_timeline_event(); + auto* expectedSurfaceFrameEndEvent = event->set_frame_end(); - expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie); - }); + expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie); + }); + } } -void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset) const { +void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const { int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing(); + bool traced = false; // Actual timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + const auto timestamp = [&]() { + std::scoped_lock lock(mMutex); + // 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 start time a little earlier than the end time so that we have some info + // about this frame in the trace. + nsecs_t endTime = + (mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime); + return endTime - kPredictionExpiredStartTimeDelta; + } + + return mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime; + }(); + + if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) { + // Do not trace packets started before tracing starts. + return; + } + traced = true; + std::scoped_lock lock(mMutex); auto packet = ctx.NewTracePacket(); 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 - // start time a little earlier than the end time so that we have some info about this - // frame in the trace. - nsecs_t endTime = - (mPresentState == PresentState::Dropped ? mDropTime : mActuals.endTime); - const auto timestamp = endTime - kPredictionExpiredStartTimeDelta; - packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); - } else { - const auto timestamp = - mActuals.startTime == 0 ? mPredictions.startTime : mActuals.startTime; - packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); - } + packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); auto* event = packet->set_frame_timeline_event(); auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start(); @@ -812,28 +845,31 @@ void SurfaceFrame::traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffse actualSurfaceFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType)); }); - // Actual timeline end - FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { - std::scoped_lock lock(mMutex); - auto packet = ctx.NewTracePacket(); - packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - if (mPresentState == PresentState::Dropped) { - packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset)); - } else { - packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset)); - } + if (traced) { + // Actual timeline end + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + std::scoped_lock lock(mMutex); + auto packet = ctx.NewTracePacket(); + packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); + if (mPresentState == PresentState::Dropped) { + packet->set_timestamp(static_cast<uint64_t>(mDropTime + monoBootOffset)); + } else { + packet->set_timestamp(static_cast<uint64_t>(mActuals.endTime + monoBootOffset)); + } - auto* event = packet->set_frame_timeline_event(); - auto* actualSurfaceFrameEndEvent = event->set_frame_end(); + auto* event = packet->set_frame_timeline_event(); + auto* actualSurfaceFrameEndEvent = event->set_frame_end(); - actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie); - }); + actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie); + }); + } } /** * TODO(b/178637512): add inputEventId to the perfetto trace. */ -void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset) const { +void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const { if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID || displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) { // No packets can be traced with a missing token. @@ -842,9 +878,9 @@ void SurfaceFrame::trace(int64_t displayFrameToken, nsecs_t monoBootOffset) cons if (getPredictionState() != PredictionState::Expired) { // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in // a trace. - tracePredictions(displayFrameToken, monoBootOffset); + tracePredictions(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts); } - traceActuals(displayFrameToken, monoBootOffset); + traceActuals(displayFrameToken, monoBootOffset, filterFramesBeforeTraceStarts); } namespace impl { @@ -870,8 +906,12 @@ std::optional<TimelineItem> TokenManager::getPredictionsForToken(int64_t token) } FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid, - JankClassificationThresholds thresholds, bool useBootTimeClock) + JankClassificationThresholds thresholds, bool useBootTimeClock, + bool filterFramesBeforeTraceStarts) : mUseBootTimeClock(useBootTimeClock), + mFilterFramesBeforeTraceStarts( + FlagManager::getInstance().filter_frames_before_trace_starts() && + filterFramesBeforeTraceStarts), mMaxDisplayFrames(kDefaultMaxDisplayFrames), mTimeStats(std::move(timeStats)), mSurfaceFlingerPid(surfaceFlingerPid), @@ -1154,16 +1194,23 @@ void FrameTimeline::DisplayFrame::onCommitNotComposited() { } } -void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid, - nsecs_t monoBootOffset) const { +void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const { int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing(); + bool traced = false; // Expected timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + const auto timestamp = mSurfaceFlingerPredictions.startTime; + if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) { + // Do not trace packets started before tracing starts. + return; + } + traced = true; + auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp( - static_cast<uint64_t>(mSurfaceFlingerPredictions.startTime + monoBootOffset)); + packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); auto* event = packet->set_frame_timeline_event(); auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start(); @@ -1174,22 +1221,25 @@ void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid, expectedDisplayFrameStartEvent->set_pid(surfaceFlingerPid); }); - // Expected timeline end - FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { - auto packet = ctx.NewTracePacket(); - packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp( - static_cast<uint64_t>(mSurfaceFlingerPredictions.endTime + monoBootOffset)); + if (traced) { + // Expected timeline end + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + auto packet = ctx.NewTracePacket(); + 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(); + auto* event = packet->set_frame_timeline_event(); + auto* expectedDisplayFrameEndEvent = event->set_frame_end(); - expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie); - }); + expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie); + }); + } } void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, - nsecs_t previousPredictionPresentTime) const { + nsecs_t previousPredictionPresentTime, + bool filterFramesBeforeTraceStarts) const { nsecs_t skippedFrameStartTime = 0, skippedFramePresentTime = 0; const constexpr float kThresh = 0.5f; const constexpr float kRange = 1.5f; @@ -1215,9 +1265,17 @@ void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs // add slice if (skippedFrameStartTime != 0 && skippedFramePresentTime != 0) { int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing(); + bool traced = false; // Actual timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + if (filterFramesBeforeTraceStarts && + !shouldTraceForDataSource(ctx, skippedFrameStartTime)) { + // Do not trace packets started before tracing starts. + return; + } + traced = true; + auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); packet->set_timestamp(static_cast<uint64_t>(skippedFrameStartTime + monoBootOffset)); @@ -1238,30 +1296,40 @@ void FrameTimeline::DisplayFrame::addSkippedFrame(pid_t surfaceFlingerPid, nsecs actualDisplayFrameStartEvent->set_jank_severity_type(toProto(JankSeverityType::None)); }); - // Actual timeline end - FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { - auto packet = ctx.NewTracePacket(); - packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp(static_cast<uint64_t>(skippedFramePresentTime + monoBootOffset)); + if (traced) { + // Actual timeline end + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + auto packet = ctx.NewTracePacket(); + packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); + packet->set_timestamp( + static_cast<uint64_t>(skippedFramePresentTime + monoBootOffset)); - auto* event = packet->set_frame_timeline_event(); - auto* actualDisplayFrameEndEvent = event->set_frame_end(); + auto* event = packet->set_frame_timeline_event(); + auto* actualDisplayFrameEndEvent = event->set_frame_end(); - actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie); - }); + actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie); + }); + } } } -void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid, - nsecs_t monoBootOffset) const { +void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const { int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing(); + bool traced = false; // Actual timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + const auto timestamp = mSurfaceFlingerActuals.startTime; + if (filterFramesBeforeTraceStarts && !shouldTraceForDataSource(ctx, timestamp)) { + // Do not trace packets started before tracing starts. + return; + } + traced = true; + auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp( - static_cast<uint64_t>(mSurfaceFlingerActuals.startTime + monoBootOffset)); + packet->set_timestamp(static_cast<uint64_t>(timestamp + monoBootOffset)); auto* event = packet->set_frame_timeline_event(); auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start(); @@ -1280,22 +1348,25 @@ void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid, actualDisplayFrameStartEvent->set_jank_severity_type(toProto(mJankSeverityType)); }); - // Actual timeline end - FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { - auto packet = ctx.NewTracePacket(); - packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME); - packet->set_timestamp( - static_cast<uint64_t>(mSurfaceFlingerActuals.presentTime + monoBootOffset)); + if (traced) { + // Actual timeline end + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + auto packet = ctx.NewTracePacket(); + 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(); + auto* event = packet->set_frame_timeline_event(); + auto* actualDisplayFrameEndEvent = event->set_frame_end(); - actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie); - }); + actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie); + }); + } } nsecs_t FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, - nsecs_t previousPredictionPresentTime) const { + nsecs_t previousPredictionPresentTime, + bool filterFramesBeforeTraceStarts) const { if (mSurfaceFrames.empty()) { // We don't want to trace display frames without any surface frames updates as this cannot // be janky @@ -1311,16 +1382,17 @@ nsecs_t FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid, nsecs_t mono if (mPredictionState == PredictionState::Valid) { // Expired and unknown predictions have zeroed timestamps. This cannot be used in any // meaningful way in a trace. - tracePredictions(surfaceFlingerPid, monoBootOffset); + tracePredictions(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts); } - traceActuals(surfaceFlingerPid, monoBootOffset); + traceActuals(surfaceFlingerPid, monoBootOffset, filterFramesBeforeTraceStarts); for (auto& surfaceFrame : mSurfaceFrames) { - surfaceFrame->trace(mToken, monoBootOffset); + surfaceFrame->trace(mToken, monoBootOffset, filterFramesBeforeTraceStarts); } if (FlagManager::getInstance().add_sf_skipped_frames_to_trace()) { - addSkippedFrame(surfaceFlingerPid, monoBootOffset, previousPredictionPresentTime); + addSkippedFrame(surfaceFlingerPid, monoBootOffset, previousPredictionPresentTime, + filterFramesBeforeTraceStarts); } return mSurfaceFlingerPredictions.presentTime; } @@ -1414,8 +1486,9 @@ void FrameTimeline::flushPendingPresentFences() { const nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID; auto& displayFrame = pendingPresentFence.second; displayFrame->onPresent(signalTime, mPreviousActualPresentTime); - mPreviousPredictionPresentTime = displayFrame->trace(mSurfaceFlingerPid, monoBootOffset, - mPreviousPredictionPresentTime); + mPreviousPredictionPresentTime = + displayFrame->trace(mSurfaceFlingerPid, monoBootOffset, + mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts); mPendingPresentFences.erase(mPendingPresentFences.begin()); } @@ -1431,8 +1504,9 @@ void FrameTimeline::flushPendingPresentFences() { auto& displayFrame = pendingPresentFence.second; displayFrame->onPresent(signalTime, mPreviousActualPresentTime); - mPreviousPredictionPresentTime = displayFrame->trace(mSurfaceFlingerPid, monoBootOffset, - mPreviousPredictionPresentTime); + mPreviousPredictionPresentTime = + displayFrame->trace(mSurfaceFlingerPid, monoBootOffset, + mPreviousPredictionPresentTime, mFilterFramesBeforeTraceStarts); mPreviousActualPresentTime = signalTime; mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast<int>(i)); diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.h b/services/surfaceflinger/FrameTimeline/FrameTimeline.h index 94cfcb40b9..cffb61ee10 100644 --- a/services/surfaceflinger/FrameTimeline/FrameTimeline.h +++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.h @@ -214,7 +214,8 @@ public: // enabled. The displayFrameToken is needed to link the SurfaceFrame to the corresponding // 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; + void trace(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const; // Getter functions used only by FrameTimelineTests and SurfaceFrame internally TimelineItem getActuals() const; @@ -234,8 +235,10 @@ public: std::chrono::duration_cast<std::chrono::nanoseconds>(2ms).count(); private: - void tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset) const; - void traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset) const; + void tracePredictions(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const; + void traceActuals(int64_t displayFrameToken, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const; void classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate, Fps displayFrameRenderRate, nsecs_t* outDeadlineDelta) REQUIRES(mMutex); @@ -367,9 +370,15 @@ private: class FrameTimeline : public android::frametimeline::FrameTimeline { public: class FrameTimelineDataSource : public perfetto::DataSource<FrameTimelineDataSource> { - void OnSetup(const SetupArgs&) override{}; - void OnStart(const StartArgs&) override{}; - void OnStop(const StopArgs&) override{}; + public: + nsecs_t getStartTime() const { return mTraceStartTime; } + + private: + void OnSetup(const SetupArgs&) override {}; + void OnStart(const StartArgs&) override { mTraceStartTime = systemTime(); }; + void OnStop(const StopArgs&) override {}; + + nsecs_t mTraceStartTime = 0; }; /* @@ -390,7 +399,8 @@ public: // is enabled. monoBootOffset is the difference between SYSTEM_TIME_BOOTTIME // and SYSTEM_TIME_MONOTONIC. nsecs_t trace(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, - nsecs_t previousPredictionPresentTime) const; + nsecs_t previousPredictionPresentTime, + bool filterFramesBeforeTraceStarts) const; // Sets the token, vsyncPeriod, predictions and SF start time. void onSfWakeUp(int64_t token, Fps refreshRate, Fps renderRate, std::optional<TimelineItem> predictions, nsecs_t wakeUpTime); @@ -424,10 +434,13 @@ public: private: void dump(std::string& result, nsecs_t baseTime) const; - void tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const; - void traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset) const; + void tracePredictions(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const; + void traceActuals(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, + bool filterFramesBeforeTraceStarts) const; void addSkippedFrame(pid_t surfaceFlingerPid, nsecs_t monoBootOffset, - nsecs_t previousActualPresentTime) const; + nsecs_t previousActualPresentTime, + bool filterFramesBeforeTraceStarts) const; void classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync, nsecs_t previousPresentTime); @@ -471,7 +484,8 @@ public: }; FrameTimeline(std::shared_ptr<TimeStats> timeStats, pid_t surfaceFlingerPid, - JankClassificationThresholds thresholds = {}, bool useBootTimeClock = true); + JankClassificationThresholds thresholds = {}, bool useBootTimeClock = true, + bool filterFramesBeforeTraceStarts = true); ~FrameTimeline() = default; frametimeline::TokenManager* getTokenManager() override { return &mTokenManager; } @@ -516,6 +530,7 @@ private: TraceCookieCounter mTraceCookieCounter; mutable std::mutex mMutex; const bool mUseBootTimeClock; + const bool mFilterFramesBeforeTraceStarts; uint32_t mMaxDisplayFrames; std::shared_ptr<TimeStats> mTimeStats; const pid_t mSurfaceFlingerPid; diff --git a/services/surfaceflinger/common/FlagManager.cpp b/services/surfaceflinger/common/FlagManager.cpp index 08412cb8e4..12d6138675 100644 --- a/services/surfaceflinger/common/FlagManager.cpp +++ b/services/surfaceflinger/common/FlagManager.cpp @@ -143,6 +143,7 @@ void FlagManager::dump(std::string& result) const { DUMP_READ_ONLY_FLAG(ce_fence_promise); DUMP_READ_ONLY_FLAG(idle_screen_refresh_rate_timeout); DUMP_READ_ONLY_FLAG(graphite_renderengine); + DUMP_READ_ONLY_FLAG(filter_frames_before_trace_starts); DUMP_READ_ONLY_FLAG(latch_unsignaled_with_auto_refresh_changed); DUMP_READ_ONLY_FLAG(deprecate_vsync_sf); DUMP_READ_ONLY_FLAG(allow_n_vsyncs_in_targeter); @@ -248,6 +249,7 @@ FLAG_MANAGER_READ_ONLY_FLAG(vrr_bugfix_24q4, ""); FLAG_MANAGER_READ_ONLY_FLAG(vrr_bugfix_dropped_frame, "") FLAG_MANAGER_READ_ONLY_FLAG(ce_fence_promise, ""); FLAG_MANAGER_READ_ONLY_FLAG(graphite_renderengine, "debug.renderengine.graphite") +FLAG_MANAGER_READ_ONLY_FLAG(filter_frames_before_trace_starts, "") FLAG_MANAGER_READ_ONLY_FLAG(latch_unsignaled_with_auto_refresh_changed, ""); FLAG_MANAGER_READ_ONLY_FLAG(deprecate_vsync_sf, ""); FLAG_MANAGER_READ_ONLY_FLAG(allow_n_vsyncs_in_targeter, ""); diff --git a/services/surfaceflinger/common/include/common/FlagManager.h b/services/surfaceflinger/common/include/common/FlagManager.h index ab0ea3bdaa..a1be19421b 100644 --- a/services/surfaceflinger/common/include/common/FlagManager.h +++ b/services/surfaceflinger/common/include/common/FlagManager.h @@ -81,6 +81,7 @@ public: bool ce_fence_promise() const; bool idle_screen_refresh_rate_timeout() const; bool graphite_renderengine() const; + bool filter_frames_before_trace_starts() const; bool latch_unsignaled_with_auto_refresh_changed() const; bool deprecate_vsync_sf() const; bool allow_n_vsyncs_in_targeter() const; diff --git a/services/surfaceflinger/surfaceflinger_flags_new.aconfig b/services/surfaceflinger/surfaceflinger_flags_new.aconfig index fcfeaccee7..102e2b643c 100644 --- a/services/surfaceflinger/surfaceflinger_flags_new.aconfig +++ b/services/surfaceflinger/surfaceflinger_flags_new.aconfig @@ -66,6 +66,17 @@ flag { } # detached_mirror flag { + name: "filter_frames_before_trace_starts" + namespace: "core_graphics" + description: "Do not trace FrameTimeline events for frames started before the trace started" + bug: "364194637" + is_fixed_read_only: true + metadata { + purpose: PURPOSE_BUGFIX + } +} # filter_frames_before_trace_starts + +flag { name: "flush_buffer_slots_to_uncache" namespace: "core_graphics" description: "Flush DisplayCommands for disabled displays in order to uncache requested buffers." diff --git a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp index 9be0fc38b3..0dfbd6185e 100644 --- a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp +++ b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp @@ -84,9 +84,11 @@ public: void SetUp() override { constexpr bool kUseBootTimeClock = true; + constexpr bool kFilterFramesBeforeTraceStarts = false; mTimeStats = std::make_shared<mock::TimeStats>(); mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats, kSurfaceFlingerPid, - kTestThresholds, !kUseBootTimeClock); + kTestThresholds, !kUseBootTimeClock, + kFilterFramesBeforeTraceStarts); mFrameTimeline->registerDataSource(); mTokenManager = &mFrameTimeline->mTokenManager; mTraceCookieCounter = &mFrameTimeline->mTraceCookieCounter; |