diff options
Diffstat (limited to 'services/surfaceflinger/FrameTimeline/FrameTimeline.cpp')
| -rw-r--r-- | services/surfaceflinger/FrameTimeline/FrameTimeline.cpp | 1304 |
1 files changed, 0 insertions, 1304 deletions
diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp deleted file mode 100644 index c294ff2695..0000000000 --- a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp +++ /dev/null @@ -1,1304 +0,0 @@ -/* - * 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 <android-base/stringprintf.h> -#include <utils/Log.h> -#include <utils/Trace.h> - -#include <chrono> -#include <cinttypes> -#include <numeric> -#include <unordered_set> - -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<double, std::milli>(startTime).count(), - std::chrono::duration<double, std::milli>(endTime).count(), - std::chrono::duration<double, std::milli>(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<nsecs_t>(0, actuals.startTime - baseTime)); - StringAppendF(&result, "\t%10.2f\t|", - std::chrono::duration<double, std::milli>(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<double, std::milli>(endTime).count()); - } - if (actuals.presentTime == 0) { - StringAppendF(&result, "\t\tN/A\n"); - } else { - std::chrono::nanoseconds presentTime(std::max<nsecs_t>(0, actuals.presentTime - baseTime)); - StringAppendF(&result, "\t%10.2f\n", - std::chrono::duration<double, std::milli>(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<std::string> 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<nsecs_t>::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> 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<std::mutex> lock(mMutex); - mRenderRate = renderRate; -} - -void SurfaceFrame::setGpuComposition() { - std::scoped_lock lock(mMutex); - mGpuComposition = true; -} - -std::optional<int32_t> 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<double, std::milli>(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<int64_t>(0), mLastLatchTime - baseTime)); - StringAppendF(&result, "%s", indent.c_str()); - StringAppendF(&result, "Last latch time: %10f\n", - std::chrono::duration<double, std::milli>(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<double, std::milli>(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<uint64_t>(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<uint64_t>(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<uint64_t>(endTime - kPredictionExpiredStartTimeDelta)); - } else { - packet->set_timestamp(static_cast<uint64_t>(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<uint64_t>(mDropTime)); - } else { - packet->set_timestamp(static_cast<uint64_t>(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<TimelineItem> 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> timeStats, pid_t surfaceFlingerPid, - JankClassificationThresholds thresholds) - : mMaxDisplayFrames(kDefaultMaxDisplayFrames), - mTimeStats(std::move(timeStats)), - mSurfaceFlingerPid(surfaceFlingerPid), - mJankClassificationThresholds(thresholds) { - mCurrentDisplayFrame = - std::make_shared<DisplayFrame>(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<SurfaceFrame> 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<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId, - std::move(layerName), std::move(debugName), - PredictionState::None, TimelineItem(), mTimeStats, - mJankClassificationThresholds, &mTraceCookieCounter, - isBuffer, gameMode); - } - std::optional<TimelineItem> predictions = - mTokenManager.getPredictionsForToken(frameTimelineInfo.vsyncId); - if (predictions) { - return std::make_shared<SurfaceFrame>(frameTimelineInfo, ownerPid, ownerUid, layerId, - std::move(layerName), std::move(debugName), - PredictionState::Valid, std::move(*predictions), - mTimeStats, mJankClassificationThresholds, - &mTraceCookieCounter, isBuffer, gameMode); - } - return std::make_shared<SurfaceFrame>(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> 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> 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<FenceTime>& presentFence, - const std::shared_ptr<FenceTime>& 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> surfaceFrame) { - mSurfaceFrames.push_back(surfaceFrame); -} - -void FrameTimeline::DisplayFrame::onSfWakeUp(int64_t token, Fps refreshRate, - std::optional<TimelineItem> 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<FenceTime>& 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<uint64_t>(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<uint64_t>(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<uint64_t>(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<uint64_t>(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<int32_t>& layerIds) { - if (layerIds.empty()) { - return 0.0f; - } - - std::vector<nsecs_t> 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<std::chrono::nanoseconds>(1s).count(); - // (10^9 nanoseconds / second) * (N present deltas) / (total nanoseconds in N present deltas) = - // M frames / second - return kOneSecond * static_cast<nsecs_t>((presentTimes.size() - 1)) / - static_cast<float>(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<int>(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<DisplayFrame>(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<double, std::milli>(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<double, std::milli>(presentDeltaNs).count()); - std::chrono::nanoseconds deltaToVsync(std::abs(presentDelta) % mRefreshRate.getPeriodNsecs()); - StringAppendF(&result, "Present delta %% refreshrate: %10f\n", - std::chrono::duration<double, std::milli>(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<int>(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<int>(i)); - } -} - -void FrameTimeline::parseArgs(const Vector<String16>& args, std::string& result) { - ATRACE_CALL(); - std::unordered_map<std::string, bool> 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 |