/* * Copyright 2020 The Android Open Source Project * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ #undef LOG_TAG #define LOG_TAG "FrameTimeline" #define ATRACE_TAG ATRACE_TAG_GRAPHICS #include "FrameTimeline.h" #include #include #include #include #include #include #include namespace android::frametimeline { using base::StringAppendF; using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent; using FrameTimelineDataSource = impl::FrameTimeline::FrameTimelineDataSource; void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals, const std::string& indent, PredictionState predictionState, nsecs_t baseTime) { StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "\t\t"); StringAppendF(&result, " Start time\t\t|"); StringAppendF(&result, " End time\t\t|"); StringAppendF(&result, " Present time\n"); if (predictionState == PredictionState::Valid) { // Dump the Predictions only if they are valid StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Expected\t|"); std::chrono::nanoseconds startTime(predictions.startTime - baseTime); std::chrono::nanoseconds endTime(predictions.endTime - baseTime); std::chrono::nanoseconds presentTime(predictions.presentTime - baseTime); StringAppendF(&result, "\t%10.2f\t|\t%10.2f\t|\t%10.2f\n", std::chrono::duration(startTime).count(), std::chrono::duration(endTime).count(), std::chrono::duration(presentTime).count()); } StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Actual \t|"); if (actuals.startTime == 0) { StringAppendF(&result, "\t\tN/A\t|"); } else { std::chrono::nanoseconds startTime(std::max(0, actuals.startTime - baseTime)); StringAppendF(&result, "\t%10.2f\t|", std::chrono::duration(startTime).count()); } if (actuals.endTime <= 0) { // Animation leashes can send the endTime as -1 StringAppendF(&result, "\t\tN/A\t|"); } else { std::chrono::nanoseconds endTime(actuals.endTime - baseTime); StringAppendF(&result, "\t%10.2f\t|", std::chrono::duration(endTime).count()); } if (actuals.presentTime == 0) { StringAppendF(&result, "\t\tN/A\n"); } else { std::chrono::nanoseconds presentTime(std::max(0, actuals.presentTime - baseTime)); StringAppendF(&result, "\t%10.2f\n", std::chrono::duration(presentTime).count()); } StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "----------------------"); StringAppendF(&result, "----------------------"); StringAppendF(&result, "----------------------"); StringAppendF(&result, "----------------------\n"); } std::string toString(PredictionState predictionState) { switch (predictionState) { case PredictionState::Valid: return "Valid"; case PredictionState::Expired: return "Expired"; case PredictionState::None: return "None"; } } std::string jankTypeBitmaskToString(int32_t jankType) { if (jankType == JankType::None) { return "None"; } std::vector janks; if (jankType & JankType::DisplayHAL) { janks.emplace_back("Display HAL"); jankType &= ~JankType::DisplayHAL; } if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) { janks.emplace_back("SurfaceFlinger CPU Deadline Missed"); jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed; } if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) { janks.emplace_back("SurfaceFlinger GPU Deadline Missed"); jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed; } if (jankType & JankType::AppDeadlineMissed) { janks.emplace_back("App Deadline Missed"); jankType &= ~JankType::AppDeadlineMissed; } if (jankType & JankType::PredictionError) { janks.emplace_back("Prediction Error"); jankType &= ~JankType::PredictionError; } if (jankType & JankType::SurfaceFlingerScheduling) { janks.emplace_back("SurfaceFlinger Scheduling"); jankType &= ~JankType::SurfaceFlingerScheduling; } if (jankType & JankType::BufferStuffing) { janks.emplace_back("Buffer Stuffing"); jankType &= ~JankType::BufferStuffing; } if (jankType & JankType::Unknown) { janks.emplace_back("Unknown jank"); jankType &= ~JankType::Unknown; } if (jankType & JankType::SurfaceFlingerStuffing) { janks.emplace_back("SurfaceFlinger Stuffing"); jankType &= ~JankType::SurfaceFlingerStuffing; } // jankType should be 0 if all types of jank were checked for. LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType); return std::accumulate(janks.begin(), janks.end(), std::string(), [](const std::string& l, const std::string& r) { return l.empty() ? r : l + ", " + r; }); } std::string toString(FramePresentMetadata presentMetadata) { switch (presentMetadata) { case FramePresentMetadata::OnTimePresent: return "On Time Present"; case FramePresentMetadata::LatePresent: return "Late Present"; case FramePresentMetadata::EarlyPresent: return "Early Present"; case FramePresentMetadata::UnknownPresent: return "Unknown Present"; } } std::string toString(FrameReadyMetadata finishMetadata) { switch (finishMetadata) { case FrameReadyMetadata::OnTimeFinish: return "On Time Finish"; case FrameReadyMetadata::LateFinish: return "Late Finish"; case FrameReadyMetadata::UnknownFinish: return "Unknown Finish"; } } std::string toString(FrameStartMetadata startMetadata) { switch (startMetadata) { case FrameStartMetadata::OnTimeStart: return "On Time Start"; case FrameStartMetadata::LateStart: return "Late Start"; case FrameStartMetadata::EarlyStart: return "Early Start"; case FrameStartMetadata::UnknownStart: return "Unknown Start"; } } std::string toString(SurfaceFrame::PresentState presentState) { using PresentState = SurfaceFrame::PresentState; switch (presentState) { case PresentState::Presented: return "Presented"; case PresentState::Dropped: return "Dropped"; case PresentState::Unknown: return "Unknown"; } } FrameTimelineEvent::PresentType toProto(FramePresentMetadata presentMetadata) { switch (presentMetadata) { case FramePresentMetadata::EarlyPresent: return FrameTimelineEvent::PRESENT_EARLY; case FramePresentMetadata::LatePresent: return FrameTimelineEvent::PRESENT_LATE; case FramePresentMetadata::OnTimePresent: return FrameTimelineEvent::PRESENT_ON_TIME; case FramePresentMetadata::UnknownPresent: return FrameTimelineEvent::PRESENT_UNSPECIFIED; } } FrameTimelineEvent::PredictionType toProto(PredictionState predictionState) { switch (predictionState) { case PredictionState::Valid: return FrameTimelineEvent::PREDICTION_VALID; case PredictionState::Expired: return FrameTimelineEvent::PREDICTION_EXPIRED; case PredictionState::None: return FrameTimelineEvent::PREDICTION_UNKNOWN; } } int32_t jankTypeBitmaskToProto(int32_t jankType) { if (jankType == JankType::None) { return FrameTimelineEvent::JANK_NONE; } int32_t protoJank = 0; if (jankType & JankType::DisplayHAL) { protoJank |= FrameTimelineEvent::JANK_DISPLAY_HAL; jankType &= ~JankType::DisplayHAL; } if (jankType & JankType::SurfaceFlingerCpuDeadlineMissed) { protoJank |= FrameTimelineEvent::JANK_SF_CPU_DEADLINE_MISSED; jankType &= ~JankType::SurfaceFlingerCpuDeadlineMissed; } if (jankType & JankType::SurfaceFlingerGpuDeadlineMissed) { protoJank |= FrameTimelineEvent::JANK_SF_GPU_DEADLINE_MISSED; jankType &= ~JankType::SurfaceFlingerGpuDeadlineMissed; } if (jankType & JankType::AppDeadlineMissed) { protoJank |= FrameTimelineEvent::JANK_APP_DEADLINE_MISSED; jankType &= ~JankType::AppDeadlineMissed; } if (jankType & JankType::PredictionError) { protoJank |= FrameTimelineEvent::JANK_PREDICTION_ERROR; jankType &= ~JankType::PredictionError; } if (jankType & JankType::SurfaceFlingerScheduling) { protoJank |= FrameTimelineEvent::JANK_SF_SCHEDULING; jankType &= ~JankType::SurfaceFlingerScheduling; } if (jankType & JankType::BufferStuffing) { protoJank |= FrameTimelineEvent::JANK_BUFFER_STUFFING; jankType &= ~JankType::BufferStuffing; } if (jankType & JankType::Unknown) { protoJank |= FrameTimelineEvent::JANK_UNKNOWN; jankType &= ~JankType::Unknown; } if (jankType & JankType::SurfaceFlingerStuffing) { protoJank |= FrameTimelineEvent::JANK_SF_STUFFING; jankType &= ~JankType::SurfaceFlingerStuffing; } // jankType should be 0 if all types of jank were checked for. LOG_ALWAYS_FATAL_IF(jankType != 0, "Unrecognized jank type value 0x%x", jankType); return protoJank; } // Returns the smallest timestamp from the set of predictions and actuals. nsecs_t getMinTime(PredictionState predictionState, TimelineItem predictions, TimelineItem actuals) { nsecs_t minTime = std::numeric_limits::max(); if (predictionState == PredictionState::Valid) { // Checking start time for predictions is enough because start time is always lesser than // endTime and presentTime. minTime = std::min(minTime, predictions.startTime); } // Need to check startTime, endTime and presentTime for actuals because some frames might not // have them set. if (actuals.startTime != 0) { minTime = std::min(minTime, actuals.startTime); } if (actuals.endTime != 0) { minTime = std::min(minTime, actuals.endTime); } if (actuals.presentTime != 0) { minTime = std::min(minTime, actuals.endTime); } return minTime; } int64_t TraceCookieCounter::getCookieForTracing() { return ++mTraceCookie; } SurfaceFrame::SurfaceFrame(const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId, std::string layerName, std::string debugName, PredictionState predictionState, frametimeline::TimelineItem&& predictions, std::shared_ptr timeStats, JankClassificationThresholds thresholds, TraceCookieCounter* traceCookieCounter, bool isBuffer, int32_t gameMode) : mToken(frameTimelineInfo.vsyncId), mInputEventId(frameTimelineInfo.inputEventId), mOwnerPid(ownerPid), mOwnerUid(ownerUid), mLayerName(std::move(layerName)), mDebugName(std::move(debugName)), mLayerId(layerId), mPresentState(PresentState::Unknown), mPredictionState(predictionState), mPredictions(predictions), mActuals({0, 0, 0}), mTimeStats(timeStats), mJankClassificationThresholds(thresholds), mTraceCookieCounter(*traceCookieCounter), mIsBuffer(isBuffer), mGameMode(gameMode) {} void SurfaceFrame::setActualStartTime(nsecs_t actualStartTime) { std::scoped_lock lock(mMutex); mActuals.startTime = actualStartTime; } void SurfaceFrame::setActualQueueTime(nsecs_t actualQueueTime) { std::scoped_lock lock(mMutex); mActualQueueTime = actualQueueTime; } void SurfaceFrame::setAcquireFenceTime(nsecs_t acquireFenceTime) { std::scoped_lock lock(mMutex); mActuals.endTime = std::max(acquireFenceTime, mActualQueueTime); } void SurfaceFrame::setDropTime(nsecs_t dropTime) { std::scoped_lock lock(mMutex); mDropTime = dropTime; } void SurfaceFrame::setPresentState(PresentState presentState, nsecs_t lastLatchTime) { std::scoped_lock lock(mMutex); LOG_ALWAYS_FATAL_IF(mPresentState != PresentState::Unknown, "setPresentState called on a SurfaceFrame from Layer - %s, that has a " "PresentState - %s set already.", mDebugName.c_str(), toString(mPresentState).c_str()); mPresentState = presentState; mLastLatchTime = lastLatchTime; } void SurfaceFrame::setRenderRate(Fps renderRate) { std::lock_guard lock(mMutex); mRenderRate = renderRate; } void SurfaceFrame::setGpuComposition() { std::scoped_lock lock(mMutex); mGpuComposition = true; } std::optional SurfaceFrame::getJankType() const { std::scoped_lock lock(mMutex); if (mPresentState == PresentState::Dropped) { // Return no jank if it's a dropped frame since we cannot attribute a jank to a it. return JankType::None; } if (mActuals.presentTime == 0) { // Frame hasn't been presented yet. return std::nullopt; } return mJankType; } nsecs_t SurfaceFrame::getBaseTime() const { std::scoped_lock lock(mMutex); return getMinTime(mPredictionState, mPredictions, mActuals); } TimelineItem SurfaceFrame::getActuals() const { std::scoped_lock lock(mMutex); return mActuals; } PredictionState SurfaceFrame::getPredictionState() const { std::scoped_lock lock(mMutex); return mPredictionState; } SurfaceFrame::PresentState SurfaceFrame::getPresentState() const { std::scoped_lock lock(mMutex); return mPresentState; } FramePresentMetadata SurfaceFrame::getFramePresentMetadata() const { std::scoped_lock lock(mMutex); return mFramePresentMetadata; } FrameReadyMetadata SurfaceFrame::getFrameReadyMetadata() const { std::scoped_lock lock(mMutex); return mFrameReadyMetadata; } nsecs_t SurfaceFrame::getDropTime() const { std::scoped_lock lock(mMutex); return mDropTime; } void SurfaceFrame::promoteToBuffer() { std::scoped_lock lock(mMutex); LOG_ALWAYS_FATAL_IF(mIsBuffer == true, "Trying to promote an already promoted BufferSurfaceFrame from layer %s " "with token %" PRId64 "", mDebugName.c_str(), mToken); mIsBuffer = true; } bool SurfaceFrame::getIsBuffer() const { std::scoped_lock lock(mMutex); return mIsBuffer; } void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t baseTime) const { std::scoped_lock lock(mMutex); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Layer - %s", mDebugName.c_str()); if (mJankType != JankType::None) { // Easily identify a janky Surface Frame in the dump StringAppendF(&result, " [*] "); } StringAppendF(&result, "\n"); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Token: %" PRId64 "\n", mToken); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Owner Pid : %d\n", mOwnerPid); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Scheduled rendering rate: %d fps\n", mRenderRate ? mRenderRate->getIntValue() : 0); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Layer ID : %d\n", mLayerId); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str()); StringAppendF(&result, "%s", indent.c_str()); if (mPresentState == PresentState::Dropped) { std::chrono::nanoseconds dropTime(mDropTime - baseTime); StringAppendF(&result, "Drop time : %10f\n", std::chrono::duration(dropTime).count()); StringAppendF(&result, "%s", indent.c_str()); } StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str()); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str()); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str()); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str()); std::chrono::nanoseconds latchTime( std::max(static_cast(0), mLastLatchTime - baseTime)); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Last latch time: %10f\n", std::chrono::duration(latchTime).count()); if (mPredictionState == PredictionState::Valid) { nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime; std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta)); StringAppendF(&result, "%s", indent.c_str()); StringAppendF(&result, "Present delta: %10f\n", std::chrono::duration(presentDeltaNs).count()); } dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime); } std::string SurfaceFrame::miniDump() const { std::scoped_lock lock(mMutex); std::string result; StringAppendF(&result, "Layer - %s\n", mDebugName.c_str()); StringAppendF(&result, "Token: %" PRId64 "\n", mToken); StringAppendF(&result, "Is Buffer?: %d\n", mIsBuffer); StringAppendF(&result, "Present State : %s\n", toString(mPresentState).c_str()); StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str()); StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str()); StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str()); StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str()); StringAppendF(&result, "Present time: %" PRId64 "", mActuals.presentTime); return result; } void SurfaceFrame::classifyJankLocked(int32_t displayFrameJankType, const Fps& refreshRate, nsecs_t& deadlineDelta) { if (mPredictionState == PredictionState::Expired || mActuals.presentTime == Fence::SIGNAL_TIME_INVALID) { // Cannot do any classification for invalid present time. // For prediction expired case, we do not know what happened here to classify this // correctly. This could potentially be AppDeadlineMissed but that's assuming no app will // request frames 120ms apart. mJankType = JankType::Unknown; deadlineDelta = -1; return; } if (mPredictionState == PredictionState::None) { // Cannot do jank classification on frames that don't have a token. return; } deadlineDelta = mActuals.endTime - mPredictions.endTime; const nsecs_t presentDelta = mActuals.presentTime - mPredictions.presentTime; const nsecs_t deltaToVsync = refreshRate.getPeriodNsecs() > 0 ? std::abs(presentDelta) % refreshRate.getPeriodNsecs() : 0; if (deadlineDelta > mJankClassificationThresholds.deadlineThreshold) { mFrameReadyMetadata = FrameReadyMetadata::LateFinish; } else { mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish; } if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) { mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent : FramePresentMetadata::EarlyPresent; } else { mFramePresentMetadata = FramePresentMetadata::OnTimePresent; } if (mFramePresentMetadata == FramePresentMetadata::OnTimePresent) { // Frames presented on time are not janky. mJankType = JankType::None; } else if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) { if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) { // Finish on time, Present early if (deltaToVsync < mJankClassificationThresholds.presentThreshold || deltaToVsync >= refreshRate.getPeriodNsecs() - mJankClassificationThresholds.presentThreshold) { // Delta factor of vsync mJankType = JankType::SurfaceFlingerScheduling; } else { // Delta not a factor of vsync mJankType = JankType::PredictionError; } } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) { // Finish late, Present early mJankType = JankType::Unknown; } } else { if (mLastLatchTime != 0 && mPredictions.endTime <= mLastLatchTime) { // Buffer Stuffing. mJankType |= JankType::BufferStuffing; // In a stuffed state, the frame could be stuck on a dequeue wait for quite some time. // Because of this dequeue wait, it can be hard to tell if a frame was genuinely late. // We try to do this by moving the deadline. Since the queue could be stuffed by more // than one buffer, we take the last latch time as reference and give one vsync // worth of time for the frame to be ready. nsecs_t adjustedDeadline = mLastLatchTime + refreshRate.getPeriodNsecs(); if (adjustedDeadline > mActuals.endTime) { mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish; } else { mFrameReadyMetadata = FrameReadyMetadata::LateFinish; } } if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) { // Finish on time, Present late if (displayFrameJankType != JankType::None) { // Propagate displayFrame's jank if it exists mJankType |= displayFrameJankType; } else { if (!(mJankType & JankType::BufferStuffing)) { // In a stuffed state, if the app finishes on time and there is no display frame // jank, only buffer stuffing is the root cause of the jank. if (deltaToVsync < mJankClassificationThresholds.presentThreshold || deltaToVsync >= refreshRate.getPeriodNsecs() - mJankClassificationThresholds.presentThreshold) { // Delta factor of vsync mJankType |= JankType::SurfaceFlingerScheduling; } else { // Delta not a factor of vsync mJankType |= JankType::PredictionError; } } } } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) { // Finish late, Present late mJankType |= JankType::AppDeadlineMissed; // Propagate DisplayFrame's jankType if it is janky mJankType |= displayFrameJankType; } } } void SurfaceFrame::onPresent(nsecs_t presentTime, int32_t displayFrameJankType, Fps refreshRate, nsecs_t displayDeadlineDelta, nsecs_t displayPresentDelta) { std::scoped_lock lock(mMutex); if (mPresentState != PresentState::Presented) { // No need to update dropped buffers return; } mActuals.presentTime = presentTime; nsecs_t deadlineDelta = 0; classifyJankLocked(displayFrameJankType, refreshRate, deadlineDelta); if (mPredictionState != PredictionState::None) { // Only update janky frames if the app used vsync predictions mTimeStats->incrementJankyFrames({refreshRate, mRenderRate, mOwnerUid, mLayerName, mGameMode, mJankType, displayDeadlineDelta, displayPresentDelta, deadlineDelta}); } } void SurfaceFrame::tracePredictions(int64_t displayFrameToken) const { int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing(); // Expected timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { std::scoped_lock lock(mMutex); auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); packet->set_timestamp(static_cast(mPredictions.startTime)); auto* event = packet->set_frame_timeline_event(); auto* expectedSurfaceFrameStartEvent = event->set_expected_surface_frame_start(); expectedSurfaceFrameStartEvent->set_cookie(expectedTimelineCookie); expectedSurfaceFrameStartEvent->set_token(mToken); expectedSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken); expectedSurfaceFrameStartEvent->set_pid(mOwnerPid); 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_MONOTONIC); packet->set_timestamp(static_cast(mPredictions.endTime)); auto* event = packet->set_frame_timeline_event(); auto* expectedSurfaceFrameEndEvent = event->set_frame_end(); expectedSurfaceFrameEndEvent->set_cookie(expectedTimelineCookie); }); } void SurfaceFrame::traceActuals(int64_t displayFrameToken) const { int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing(); // Actual timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { std::scoped_lock lock(mMutex); auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); // 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); packet->set_timestamp( static_cast(endTime - kPredictionExpiredStartTimeDelta)); } else { packet->set_timestamp(static_cast(mPredictions.startTime)); } auto* event = packet->set_frame_timeline_event(); auto* actualSurfaceFrameStartEvent = event->set_actual_surface_frame_start(); actualSurfaceFrameStartEvent->set_cookie(actualTimelineCookie); actualSurfaceFrameStartEvent->set_token(mToken); actualSurfaceFrameStartEvent->set_display_frame_token(displayFrameToken); actualSurfaceFrameStartEvent->set_pid(mOwnerPid); actualSurfaceFrameStartEvent->set_layer_name(mDebugName); if (mPresentState == PresentState::Dropped) { actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED); } else if (mPresentState == PresentState::Unknown) { actualSurfaceFrameStartEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED); } else { actualSurfaceFrameStartEvent->set_present_type(toProto(mFramePresentMetadata)); } actualSurfaceFrameStartEvent->set_on_time_finish(mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish); actualSurfaceFrameStartEvent->set_gpu_composition(mGpuComposition); actualSurfaceFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType)); actualSurfaceFrameStartEvent->set_prediction_type(toProto(mPredictionState)); actualSurfaceFrameStartEvent->set_is_buffer(mIsBuffer); }); // 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_MONOTONIC); if (mPresentState == PresentState::Dropped) { packet->set_timestamp(static_cast(mDropTime)); } else { packet->set_timestamp(static_cast(mActuals.endTime)); } auto* event = packet->set_frame_timeline_event(); auto* actualSurfaceFrameEndEvent = event->set_frame_end(); actualSurfaceFrameEndEvent->set_cookie(actualTimelineCookie); }); } /** * TODO(b/178637512): add inputEventId to the perfetto trace. */ void SurfaceFrame::trace(int64_t displayFrameToken) const { if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID || displayFrameToken == FrameTimelineInfo::INVALID_VSYNC_ID) { // No packets can be traced with a missing token. return; } if (getPredictionState() != PredictionState::Expired) { // Expired predictions have zeroed timestamps. This cannot be used in any meaningful way in // a trace. tracePredictions(displayFrameToken); } traceActuals(displayFrameToken); } namespace impl { int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) { ATRACE_CALL(); std::scoped_lock lock(mMutex); while (mPredictions.size() >= kMaxTokens) { mPredictions.erase(mPredictions.begin()); } const int64_t assignedToken = mCurrentToken++; mPredictions[assignedToken] = predictions; return assignedToken; } std::optional TokenManager::getPredictionsForToken(int64_t token) const { std::scoped_lock lock(mMutex); auto predictionsIterator = mPredictions.find(token); if (predictionsIterator != mPredictions.end()) { return predictionsIterator->second; } return {}; } FrameTimeline::FrameTimeline(std::shared_ptr timeStats, pid_t surfaceFlingerPid, JankClassificationThresholds thresholds) : mMaxDisplayFrames(kDefaultMaxDisplayFrames), mTimeStats(std::move(timeStats)), mSurfaceFlingerPid(surfaceFlingerPid), mJankClassificationThresholds(thresholds) { mCurrentDisplayFrame = std::make_shared(mTimeStats, thresholds, &mTraceCookieCounter); } void FrameTimeline::onBootFinished() { perfetto::TracingInitArgs args; args.backends = perfetto::kSystemBackend; perfetto::Tracing::Initialize(args); registerDataSource(); } void FrameTimeline::registerDataSource() { perfetto::DataSourceDescriptor dsd; dsd.set_name(kFrameTimelineDataSource); FrameTimelineDataSource::Register(dsd); } std::shared_ptr FrameTimeline::createSurfaceFrameForToken( const FrameTimelineInfo& frameTimelineInfo, pid_t ownerPid, uid_t ownerUid, int32_t layerId, std::string layerName, std::string debugName, bool isBuffer, int32_t gameMode) { ATRACE_CALL(); if (frameTimelineInfo.vsyncId == FrameTimelineInfo::INVALID_VSYNC_ID) { return std::make_shared(frameTimelineInfo, ownerPid, ownerUid, layerId, std::move(layerName), std::move(debugName), PredictionState::None, TimelineItem(), mTimeStats, mJankClassificationThresholds, &mTraceCookieCounter, isBuffer, gameMode); } std::optional predictions = mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId); if (predictions) { return std::make_shared(frameTimelineInfo, ownerPid, ownerUid, layerId, std::move(layerName), std::move(debugName), PredictionState::Valid, std::move(*predictions), mTimeStats, mJankClassificationThresholds, &mTraceCookieCounter, isBuffer, gameMode); } return std::make_shared(frameTimelineInfo, ownerPid, ownerUid, layerId, std::move(layerName), std::move(debugName), PredictionState::Expired, TimelineItem(), mTimeStats, mJankClassificationThresholds, &mTraceCookieCounter, isBuffer, gameMode); } FrameTimeline::DisplayFrame::DisplayFrame(std::shared_ptr timeStats, JankClassificationThresholds thresholds, TraceCookieCounter* traceCookieCounter) : mSurfaceFlingerPredictions(TimelineItem()), mSurfaceFlingerActuals(TimelineItem()), mTimeStats(timeStats), mJankClassificationThresholds(thresholds), mTraceCookieCounter(*traceCookieCounter) { mSurfaceFrames.reserve(kNumSurfaceFramesInitial); } void FrameTimeline::addSurfaceFrame(std::shared_ptr surfaceFrame) { ATRACE_CALL(); std::scoped_lock lock(mMutex); mCurrentDisplayFrame->addSurfaceFrame(surfaceFrame); } void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime, Fps refreshRate) { ATRACE_CALL(); std::scoped_lock lock(mMutex); mCurrentDisplayFrame->onSfWakeUp(token, refreshRate, mTokenManager.getPredictionsForToken(token), wakeUpTime); } void FrameTimeline::setSfPresent(nsecs_t sfPresentTime, const std::shared_ptr& presentFence, const std::shared_ptr& gpuFence) { ATRACE_CALL(); std::scoped_lock lock(mMutex); mCurrentDisplayFrame->setActualEndTime(sfPresentTime); mCurrentDisplayFrame->setGpuFence(gpuFence); mPendingPresentFences.emplace_back(std::make_pair(presentFence, mCurrentDisplayFrame)); flushPendingPresentFences(); finalizeCurrentDisplayFrame(); } void FrameTimeline::DisplayFrame::addSurfaceFrame(std::shared_ptr surfaceFrame) { mSurfaceFrames.push_back(surfaceFrame); } void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate, std::optional predictions, nsecs_t wakeUpTime) { mToken = token; mRefreshRate = refreshRate; if (!predictions) { mPredictionState = PredictionState::Expired; } else { mPredictionState = PredictionState::Valid; mSurfaceFlingerPredictions = *predictions; } mSurfaceFlingerActuals.startTime = wakeUpTime; } void FrameTimeline::DisplayFrame::setPredictions(PredictionState predictionState, TimelineItem predictions) { mPredictionState = predictionState; mSurfaceFlingerPredictions = predictions; } void FrameTimeline::DisplayFrame::setActualStartTime(nsecs_t actualStartTime) { mSurfaceFlingerActuals.startTime = actualStartTime; } void FrameTimeline::DisplayFrame::setActualEndTime(nsecs_t actualEndTime) { mSurfaceFlingerActuals.endTime = actualEndTime; } void FrameTimeline::DisplayFrame::setGpuFence(const std::shared_ptr& gpuFence) { mGpuFence = gpuFence; } void FrameTimeline::DisplayFrame::classifyJank(nsecs_t& deadlineDelta, nsecs_t& deltaToVsync, nsecs_t previousPresentTime) { if (mPredictionState == PredictionState::Expired || mSurfaceFlingerActuals.presentTime == Fence::SIGNAL_TIME_INVALID) { // Cannot do jank classification with expired predictions or invalid signal times. Set the // deltas to 0 as both negative and positive deltas are used as real values. mJankType = JankType::Unknown; deadlineDelta = 0; deltaToVsync = 0; return; } // Delta between the expected present and the actual present const nsecs_t presentDelta = mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime; // Sf actual end time represents the CPU end time. In case of HWC, SF's end time would have // included the time for composition. However, for GPU composition, the final end time is max(sf // end time, gpu fence time). nsecs_t combinedEndTime = mSurfaceFlingerActuals.endTime; if (mGpuFence != FenceTime::NO_FENCE) { combinedEndTime = std::max(combinedEndTime, mGpuFence->getSignalTime()); } deadlineDelta = combinedEndTime - mSurfaceFlingerPredictions.endTime; // How far off was the presentDelta when compared to the vsyncPeriod. Used in checking if there // was a prediction error or not. deltaToVsync = mRefreshRate.getPeriodNsecs() > 0 ? std::abs(presentDelta) % mRefreshRate.getPeriodNsecs() : 0; if (std::abs(presentDelta) > mJankClassificationThresholds.presentThreshold) { mFramePresentMetadata = presentDelta > 0 ? FramePresentMetadata::LatePresent : FramePresentMetadata::EarlyPresent; } else { mFramePresentMetadata = FramePresentMetadata::OnTimePresent; } if (combinedEndTime > mSurfaceFlingerPredictions.endTime) { mFrameReadyMetadata = FrameReadyMetadata::LateFinish; } else { mFrameReadyMetadata = FrameReadyMetadata::OnTimeFinish; } if (std::abs(mSurfaceFlingerActuals.startTime - mSurfaceFlingerPredictions.startTime) > mJankClassificationThresholds.startThreshold) { mFrameStartMetadata = mSurfaceFlingerActuals.startTime > mSurfaceFlingerPredictions.startTime ? FrameStartMetadata::LateStart : FrameStartMetadata::EarlyStart; } if (mFramePresentMetadata != FramePresentMetadata::OnTimePresent) { // Do jank classification only if present is not on time if (mFramePresentMetadata == FramePresentMetadata::EarlyPresent) { if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish) { // Finish on time, Present early if (deltaToVsync < mJankClassificationThresholds.presentThreshold || deltaToVsync >= (mRefreshRate.getPeriodNsecs() - mJankClassificationThresholds.presentThreshold)) { // Delta is a factor of vsync if its within the presentTheshold on either side // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms. mJankType = JankType::SurfaceFlingerScheduling; } else { // Delta is not a factor of vsync, mJankType = JankType::PredictionError; } } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) { // Finish late, Present early mJankType = JankType::SurfaceFlingerScheduling; } else { // Finish time unknown mJankType = JankType::Unknown; } } else if (mFramePresentMetadata == FramePresentMetadata::LatePresent) { if (std::abs(mSurfaceFlingerPredictions.presentTime - previousPresentTime) <= mJankClassificationThresholds.presentThreshold || previousPresentTime > mSurfaceFlingerPredictions.presentTime) { // The previous frame was either presented in the current frame's expected vsync or // it was presented even later than the current frame's expected vsync. mJankType = JankType::SurfaceFlingerStuffing; } if (mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish && !(mJankType & JankType::SurfaceFlingerStuffing)) { // Finish on time, Present late if (deltaToVsync < mJankClassificationThresholds.presentThreshold || deltaToVsync >= (mRefreshRate.getPeriodNsecs() - mJankClassificationThresholds.presentThreshold)) { // Delta is a factor of vsync if its within the presentTheshold on either side // of the vsyncPeriod. Example: 0-2ms and 9-11ms are both within the threshold // of the vsyncPeriod if the threshold was 2ms and the vsyncPeriod was 11ms. mJankType = JankType::DisplayHAL; } else { // Delta is not a factor of vsync mJankType = JankType::PredictionError; } } else if (mFrameReadyMetadata == FrameReadyMetadata::LateFinish) { if (!(mJankType & JankType::SurfaceFlingerStuffing) || mSurfaceFlingerActuals.presentTime - previousPresentTime > mRefreshRate.getPeriodNsecs() + mJankClassificationThresholds.presentThreshold) { // Classify CPU vs GPU if SF wasn't stuffed or if SF was stuffed but this frame // was presented more than a vsync late. if (mGpuFence != FenceTime::NO_FENCE && mSurfaceFlingerActuals.endTime - mSurfaceFlingerActuals.startTime < mRefreshRate.getPeriodNsecs()) { // If SF was in GPU composition and the CPU work finished before the vsync // period, classify it as GPU deadline missed. mJankType = JankType::SurfaceFlingerGpuDeadlineMissed; } else { mJankType = JankType::SurfaceFlingerCpuDeadlineMissed; } } } else { // Finish time unknown mJankType = JankType::Unknown; } } else { // Present unknown mJankType = JankType::Unknown; } } } void FrameTimeline::DisplayFrame::onPresent(nsecs_t signalTime, nsecs_t previousPresentTime) { mSurfaceFlingerActuals.presentTime = signalTime; nsecs_t deadlineDelta = 0; nsecs_t deltaToVsync = 0; classifyJank(deadlineDelta, deltaToVsync, previousPresentTime); for (auto& surfaceFrame : mSurfaceFrames) { surfaceFrame->onPresent(signalTime, mJankType, mRefreshRate, deadlineDelta, deltaToVsync); } } void FrameTimeline::DisplayFrame::tracePredictions(pid_t surfaceFlingerPid) const { int64_t expectedTimelineCookie = mTraceCookieCounter.getCookieForTracing(); // Expected timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); packet->set_timestamp(static_cast(mSurfaceFlingerPredictions.startTime)); auto* event = packet->set_frame_timeline_event(); auto* expectedDisplayFrameStartEvent = event->set_expected_display_frame_start(); expectedDisplayFrameStartEvent->set_cookie(expectedTimelineCookie); expectedDisplayFrameStartEvent->set_token(mToken); 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_MONOTONIC); packet->set_timestamp(static_cast(mSurfaceFlingerPredictions.endTime)); auto* event = packet->set_frame_timeline_event(); auto* expectedDisplayFrameEndEvent = event->set_frame_end(); expectedDisplayFrameEndEvent->set_cookie(expectedTimelineCookie); }); } void FrameTimeline::DisplayFrame::traceActuals(pid_t surfaceFlingerPid) const { int64_t actualTimelineCookie = mTraceCookieCounter.getCookieForTracing(); // Actual timeline start FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); packet->set_timestamp(static_cast(mSurfaceFlingerActuals.startTime)); auto* event = packet->set_frame_timeline_event(); auto* actualDisplayFrameStartEvent = event->set_actual_display_frame_start(); actualDisplayFrameStartEvent->set_cookie(actualTimelineCookie); actualDisplayFrameStartEvent->set_token(mToken); actualDisplayFrameStartEvent->set_pid(surfaceFlingerPid); actualDisplayFrameStartEvent->set_present_type(toProto(mFramePresentMetadata)); actualDisplayFrameStartEvent->set_on_time_finish(mFrameReadyMetadata == FrameReadyMetadata::OnTimeFinish); actualDisplayFrameStartEvent->set_gpu_composition(mGpuFence != FenceTime::NO_FENCE); actualDisplayFrameStartEvent->set_jank_type(jankTypeBitmaskToProto(mJankType)); actualDisplayFrameStartEvent->set_prediction_type(toProto(mPredictionState)); }); // Actual timeline end FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { auto packet = ctx.NewTracePacket(); packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); packet->set_timestamp(static_cast(mSurfaceFlingerActuals.presentTime)); auto* event = packet->set_frame_timeline_event(); auto* actualDisplayFrameEndEvent = event->set_frame_end(); actualDisplayFrameEndEvent->set_cookie(actualTimelineCookie); }); } void FrameTimeline::DisplayFrame::trace(pid_t surfaceFlingerPid) const { if (mToken == FrameTimelineInfo::INVALID_VSYNC_ID) { // DisplayFrame should not have an invalid token. ALOGE("Cannot trace DisplayFrame with invalid token"); return; } if (mPredictionState == PredictionState::Valid) { // Expired and unknown predictions have zeroed timestamps. This cannot be used in any // meaningful way in a trace. tracePredictions(surfaceFlingerPid); } traceActuals(surfaceFlingerPid); for (auto& surfaceFrame : mSurfaceFrames) { surfaceFrame->trace(mToken); } } float FrameTimeline::computeFps(const std::unordered_set& layerIds) { if (layerIds.empty()) { return 0.0f; } std::vector presentTimes; { std::scoped_lock lock(mMutex); presentTimes.reserve(mDisplayFrames.size()); for (size_t i = 0; i < mDisplayFrames.size(); i++) { const auto& displayFrame = mDisplayFrames[i]; if (displayFrame->getActuals().presentTime <= 0) { continue; } for (const auto& surfaceFrame : displayFrame->getSurfaceFrames()) { if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented && layerIds.count(surfaceFrame->getLayerId()) > 0) { // We're looking for DisplayFrames that presents at least one layer from // layerIds, so push the present time and skip looking through the rest of the // SurfaceFrames. presentTimes.push_back(displayFrame->getActuals().presentTime); break; } } } } // FPS can't be computed when there's fewer than 2 presented frames. if (presentTimes.size() <= 1) { return 0.0f; } nsecs_t priorPresentTime = -1; nsecs_t totalPresentToPresentWalls = 0; for (const nsecs_t presentTime : presentTimes) { if (priorPresentTime == -1) { priorPresentTime = presentTime; continue; } totalPresentToPresentWalls += (presentTime - priorPresentTime); priorPresentTime = presentTime; } if (CC_UNLIKELY(totalPresentToPresentWalls <= 0)) { ALOGW("Invalid total present-to-present duration when computing fps: %" PRId64, totalPresentToPresentWalls); return 0.0f; } const constexpr nsecs_t kOneSecond = std::chrono::duration_cast(1s).count(); // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) = // M frames / second return kOneSecond * static_cast((presentTimes.size() - 1)) / static_cast(totalPresentToPresentWalls); } void FrameTimeline::flushPendingPresentFences() { for (size_t i = 0; i < mPendingPresentFences.size(); i++) { const auto& pendingPresentFence = mPendingPresentFences[i]; nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID; if (pendingPresentFence.first && pendingPresentFence.first->isValid()) { signalTime = pendingPresentFence.first->getSignalTime(); if (signalTime == Fence::SIGNAL_TIME_PENDING) { continue; } } auto& displayFrame = pendingPresentFence.second; displayFrame->onPresent(signalTime, mPreviousPresentTime); displayFrame->trace(mSurfaceFlingerPid); mPreviousPresentTime = signalTime; mPendingPresentFences.erase(mPendingPresentFences.begin() + static_cast(i)); --i; } } void FrameTimeline::finalizeCurrentDisplayFrame() { while (mDisplayFrames.size() >= mMaxDisplayFrames) { // We maintain only a fixed number of frames' data. Pop older frames mDisplayFrames.pop_front(); } mDisplayFrames.push_back(mCurrentDisplayFrame); mCurrentDisplayFrame.reset(); mCurrentDisplayFrame = std::make_shared(mTimeStats, mJankClassificationThresholds, &mTraceCookieCounter); } nsecs_t FrameTimeline::DisplayFrame::getBaseTime() const { nsecs_t baseTime = getMinTime(mPredictionState, mSurfaceFlingerPredictions, mSurfaceFlingerActuals); for (const auto& surfaceFrame : mSurfaceFrames) { nsecs_t surfaceFrameBaseTime = surfaceFrame->getBaseTime(); if (surfaceFrameBaseTime != 0) { baseTime = std::min(baseTime, surfaceFrameBaseTime); } } return baseTime; } void FrameTimeline::DisplayFrame::dumpJank(std::string& result, nsecs_t baseTime, int displayFrameCount) const { if (mJankType == JankType::None) { // Check if any Surface Frame has been janky bool isJanky = false; for (const auto& surfaceFrame : mSurfaceFrames) { if (surfaceFrame->getJankType() != JankType::None) { isJanky = true; break; } } if (!isJanky) { return; } } StringAppendF(&result, "Display Frame %d", displayFrameCount); dump(result, baseTime); } void FrameTimeline::DisplayFrame::dumpAll(std::string& result, nsecs_t baseTime) const { dump(result, baseTime); } void FrameTimeline::DisplayFrame::dump(std::string& result, nsecs_t baseTime) const { if (mJankType != JankType::None) { // Easily identify a janky Display Frame in the dump StringAppendF(&result, " [*] "); } StringAppendF(&result, "\n"); StringAppendF(&result, "Prediction State : %s\n", toString(mPredictionState).c_str()); StringAppendF(&result, "Jank Type : %s\n", jankTypeBitmaskToString(mJankType).c_str()); StringAppendF(&result, "Present Metadata : %s\n", toString(mFramePresentMetadata).c_str()); StringAppendF(&result, "Finish Metadata: %s\n", toString(mFrameReadyMetadata).c_str()); StringAppendF(&result, "Start Metadata: %s\n", toString(mFrameStartMetadata).c_str()); std::chrono::nanoseconds vsyncPeriod(mRefreshRate.getPeriodNsecs()); StringAppendF(&result, "Vsync Period: %10f\n", std::chrono::duration(vsyncPeriod).count()); nsecs_t presentDelta = mSurfaceFlingerActuals.presentTime - mSurfaceFlingerPredictions.presentTime; std::chrono::nanoseconds presentDeltaNs(std::abs(presentDelta)); StringAppendF(&result, "Present delta: %10f\n", std::chrono::duration(presentDeltaNs).count()); std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()); StringAppendF(&result, "Present delta %% refreshrate: %10f\n", std::chrono::duration(deltaToVsync).count()); dumpTable(result, mSurfaceFlingerPredictions, mSurfaceFlingerActuals, "", mPredictionState, baseTime); StringAppendF(&result, "\n"); std::string indent = " "; // 4 spaces for (const auto& surfaceFrame : mSurfaceFrames) { surfaceFrame->dump(result, indent, baseTime); } StringAppendF(&result, "\n"); } void FrameTimeline::dumpAll(std::string& result) { std::scoped_lock lock(mMutex); StringAppendF(&result, "Number of display frames : %d\n", (int)mDisplayFrames.size()); nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime(); for (size_t i = 0; i < mDisplayFrames.size(); i++) { StringAppendF(&result, "Display Frame %d", static_cast(i)); mDisplayFrames[i]->dumpAll(result, baseTime); } } void FrameTimeline::dumpJank(std::string& result) { std::scoped_lock lock(mMutex); nsecs_t baseTime = (mDisplayFrames.empty()) ? 0 : mDisplayFrames[0]->getBaseTime(); for (size_t i = 0; i < mDisplayFrames.size(); i++) { mDisplayFrames[i]->dumpJank(result, baseTime, static_cast(i)); } } void FrameTimeline::parseArgs(const Vector& args, std::string& result) { ATRACE_CALL(); std::unordered_map argsMap; for (size_t i = 0; i < args.size(); i++) { argsMap[std::string(String8(args[i]).c_str())] = true; } if (argsMap.count("-jank")) { dumpJank(result); } if (argsMap.count("-all")) { dumpAll(result); } } void FrameTimeline::setMaxDisplayFrames(uint32_t size) { std::scoped_lock lock(mMutex); // The size can either increase or decrease, clear everything, to be consistent mDisplayFrames.clear(); mPendingPresentFences.clear(); mMaxDisplayFrames = size; } void FrameTimeline::reset() { setMaxDisplayFrames(kDefaultMaxDisplayFrames); } } // namespace impl } // namespace android::frametimeline