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; |