Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 0102ad2d authored by Yiwei Zhang's avatar Yiwei Zhang
Browse files

SurfaceFlinger TimeStats Metrics

Add timestats metrics for SurfaceFlinger. Keep track of global metrics
like total frames, missed frames, frames fellback to client
compositions, etc, as well as layer timing metrics like the delta
combination of postTime, desiredPresentTime, acqureTime, latchTime,
presentTime, etc. This metric is aimed at GMScore.

Test: dumpsys SurfaceFlinger --timestats [go/sf-timestats for more args]
Bug: b/70388650
Change-Id: I6e4545aef62f7893020533a4e7521541ea453ecd
Merged-In: I6e4545aef62f7893020533a4e7521541ea453ecd
parent a296b0c2
Loading
Loading
Loading
Loading
+4 −0
Original line number Original line Diff line number Diff line
@@ -45,6 +45,7 @@ cc_defaults {
        "libpdx_default_transport",
        "libpdx_default_transport",
        "libprotobuf-cpp-lite",
        "libprotobuf-cpp-lite",
        "libsync",
        "libsync",
        "libtimestats_proto",
        "libui",
        "libui",
        "libutils",
        "libutils",
        "libvulkan",
        "libvulkan",
@@ -124,6 +125,7 @@ filegroup {
        "SurfaceFlinger.cpp",
        "SurfaceFlinger.cpp",
        "SurfaceInterceptor.cpp",
        "SurfaceInterceptor.cpp",
        "SurfaceTracing.cpp",
        "SurfaceTracing.cpp",
        "TimeStats/TimeStats.cpp",
        "Transform.cpp",
        "Transform.cpp",
    ],
    ],
}
}
@@ -172,6 +174,7 @@ cc_binary {
        "liblayers_proto",
        "liblayers_proto",
        "liblog",
        "liblog",
        "libsurfaceflinger",
        "libsurfaceflinger",
        "libtimestats_proto",
        "libutils",
        "libutils",
    ],
    ],
    static_libs: [
    static_libs: [
@@ -213,5 +216,6 @@ cc_library_shared {


subdirs = [
subdirs = [
    "layerproto",
    "layerproto",
    "TimeStats/timestatsproto",
    "tests",
    "tests",
]
]
+15 −2
Original line number Original line Diff line number Diff line
@@ -316,6 +316,9 @@ bool BufferLayer::onPostComposition(const std::shared_ptr<FenceTime>& glDoneFenc
    nsecs_t desiredPresentTime = mConsumer->getTimestamp();
    nsecs_t desiredPresentTime = mConsumer->getTimestamp();
    mFrameTracker.setDesiredPresentTime(desiredPresentTime);
    mFrameTracker.setDesiredPresentTime(desiredPresentTime);


    const std::string layerName(getName().c_str());
    mTimeStats.setDesiredTime(layerName, mCurrentFrameNumber, desiredPresentTime);

    std::shared_ptr<FenceTime> frameReadyFence = mConsumer->getCurrentFenceTime();
    std::shared_ptr<FenceTime> frameReadyFence = mConsumer->getCurrentFenceTime();
    if (frameReadyFence->isValid()) {
    if (frameReadyFence->isValid()) {
        mFrameTracker.setFrameReadyFence(std::move(frameReadyFence));
        mFrameTracker.setFrameReadyFence(std::move(frameReadyFence));
@@ -326,12 +329,15 @@ bool BufferLayer::onPostComposition(const std::shared_ptr<FenceTime>& glDoneFenc
    }
    }


    if (presentFence->isValid()) {
    if (presentFence->isValid()) {
        mTimeStats.setPresentFence(layerName, mCurrentFrameNumber, presentFence);
        mFrameTracker.setActualPresentFence(std::shared_ptr<FenceTime>(presentFence));
        mFrameTracker.setActualPresentFence(std::shared_ptr<FenceTime>(presentFence));
    } else {
    } else {
        // The HWC doesn't support present fences, so use the refresh
        // The HWC doesn't support present fences, so use the refresh
        // timestamp instead.
        // timestamp instead.
        mFrameTracker.setActualPresentTime(
        const nsecs_t actualPresentTime =
                mFlinger->getHwComposer().getRefreshTimestamp(HWC_DISPLAY_PRIMARY));
                mFlinger->getHwComposer().getRefreshTimestamp(HWC_DISPLAY_PRIMARY);
        mTimeStats.setPresentTime(layerName, mCurrentFrameNumber, actualPresentTime);
        mFrameTracker.setActualPresentTime(actualPresentTime);
    }
    }


    mFrameTracker.advanceFrame();
    mFrameTracker.advanceFrame();
@@ -441,6 +447,7 @@ Region BufferLayer::latchBuffer(bool& recomputeVisibleRegions, nsecs_t latchTime
        // and return early
        // and return early
        if (queuedBuffer) {
        if (queuedBuffer) {
            Mutex::Autolock lock(mQueueItemLock);
            Mutex::Autolock lock(mQueueItemLock);
            mTimeStats.removeTimeRecord(getName().c_str(), mQueueItems[0].mFrameNumber);
            mQueueItems.removeAt(0);
            mQueueItems.removeAt(0);
            android_atomic_dec(&mQueuedFrames);
            android_atomic_dec(&mQueuedFrames);
        }
        }
@@ -454,6 +461,7 @@ Region BufferLayer::latchBuffer(bool& recomputeVisibleRegions, nsecs_t latchTime
            Mutex::Autolock lock(mQueueItemLock);
            Mutex::Autolock lock(mQueueItemLock);
            mQueueItems.clear();
            mQueueItems.clear();
            android_atomic_and(0, &mQueuedFrames);
            android_atomic_and(0, &mQueuedFrames);
            mTimeStats.clearLayerRecord(getName().c_str());
        }
        }


        // Once we have hit this state, the shadow queue may no longer
        // Once we have hit this state, the shadow queue may no longer
@@ -474,10 +482,15 @@ Region BufferLayer::latchBuffer(bool& recomputeVisibleRegions, nsecs_t latchTime
        // Remove any stale buffers that have been dropped during
        // Remove any stale buffers that have been dropped during
        // updateTexImage
        // updateTexImage
        while (mQueueItems[0].mFrameNumber != currentFrameNumber) {
        while (mQueueItems[0].mFrameNumber != currentFrameNumber) {
            mTimeStats.removeTimeRecord(getName().c_str(), mQueueItems[0].mFrameNumber);
            mQueueItems.removeAt(0);
            mQueueItems.removeAt(0);
            android_atomic_dec(&mQueuedFrames);
            android_atomic_dec(&mQueuedFrames);
        }
        }


        const std::string layerName(getName().c_str());
        mTimeStats.setAcquireFence(layerName, currentFrameNumber, mQueueItems[0].mFenceTime);
        mTimeStats.setLatchTime(layerName, currentFrameNumber, latchTime);

        mQueueItems.removeAt(0);
        mQueueItems.removeAt(0);
    }
    }


+6 −0
Original line number Original line Diff line number Diff line
@@ -1532,10 +1532,16 @@ void Layer::dumpFrameEvents(String8& result) {
void Layer::onDisconnect() {
void Layer::onDisconnect() {
    Mutex::Autolock lock(mFrameEventHistoryMutex);
    Mutex::Autolock lock(mFrameEventHistoryMutex);
    mFrameEventHistory.onDisconnect();
    mFrameEventHistory.onDisconnect();
    mTimeStats.onDisconnect(getName().c_str());
}
}


void Layer::addAndGetFrameTimestamps(const NewFrameEventsEntry* newTimestamps,
void Layer::addAndGetFrameTimestamps(const NewFrameEventsEntry* newTimestamps,
                                     FrameEventHistoryDelta* outDelta) {
                                     FrameEventHistoryDelta* outDelta) {
    if (newTimestamps) {
        mTimeStats.setPostTime(getName().c_str(), newTimestamps->frameNumber,
                               newTimestamps->postedTime);
    }

    Mutex::Autolock lock(mFrameEventHistoryMutex);
    Mutex::Autolock lock(mFrameEventHistoryMutex);
    if (newTimestamps) {
    if (newTimestamps) {
        // If there are any unsignaled fences in the aquire timeline at this
        // If there are any unsignaled fences in the aquire timeline at this
+3 −0
Original line number Original line Diff line number Diff line
@@ -41,6 +41,7 @@
#include "LayerVector.h"
#include "LayerVector.h"
#include "MonitoredProducer.h"
#include "MonitoredProducer.h"
#include "SurfaceFlinger.h"
#include "SurfaceFlinger.h"
#include "TimeStats/TimeStats.h"
#include "Transform.h"
#include "Transform.h"


#include <layerproto/LayerProtoHeader.h>
#include <layerproto/LayerProtoHeader.h>
@@ -737,6 +738,8 @@ protected:
    FenceTimeline mAcquireTimeline;
    FenceTimeline mAcquireTimeline;
    FenceTimeline mReleaseTimeline;
    FenceTimeline mReleaseTimeline;


    TimeStats& mTimeStats = TimeStats::getInstance();

    // main thread
    // main thread
    int mActiveBufferSlot;
    int mActiveBufferSlot;
    sp<GraphicBuffer> mActiveBuffer;
    sp<GraphicBuffer> mActiveBuffer;
+21 −7
Original line number Original line Diff line number Diff line
@@ -1470,9 +1470,13 @@ void SurfaceFlinger::onMessageReceived(int32_t what) {
                            Fence::SIGNAL_TIME_PENDING);
                            Fence::SIGNAL_TIME_PENDING);
            ATRACE_INT("FrameMissed", static_cast<int>(frameMissed));
            ATRACE_INT("FrameMissed", static_cast<int>(frameMissed));
            if (mPropagateBackpressure && frameMissed) {
            if (mPropagateBackpressure && frameMissed) {
                mTimeStats.incrementMissedFrames(true);
                signalLayerUpdate();
                signalLayerUpdate();
                break;
                break;
            }
            }
            if (frameMissed) {
                mTimeStats.incrementMissedFrames(false);
            }


            // Now that we're going to make it to the handleMessageTransaction()
            // Now that we're going to make it to the handleMessageTransaction()
            // call below it's safe to call updateVrFlinger(), which will
            // call below it's safe to call updateVrFlinger(), which will
@@ -1771,6 +1775,11 @@ void SurfaceFlinger::postComposition(nsecs_t refreshStartTime)
        mAnimFrameTracker.advanceFrame();
        mAnimFrameTracker.advanceFrame();
    }
    }


    mTimeStats.incrementTotalFrames();
    if (mHadClientComposition) {
        mTimeStats.incrementClientCompositionFrames();
    }

    if (getBE().mHwc->isConnected(HWC_DISPLAY_PRIMARY) &&
    if (getBE().mHwc->isConnected(HWC_DISPLAY_PRIMARY) &&
            hw->getPowerMode() == HWC_POWER_MODE_OFF) {
            hw->getPowerMode() == HWC_POWER_MODE_OFF) {
        return;
        return;
@@ -3824,12 +3833,6 @@ status_t SurfaceFlinger::doDump(int fd, const Vector<String16>& args, bool asPro
        size_t index = 0;
        size_t index = 0;
        size_t numArgs = args.size();
        size_t numArgs = args.size();


        if (asProto) {
            LayersProto layersProto = dumpProtoInfo(LayerVector::StateSet::Current);
            result.append(layersProto.SerializeAsString().c_str(), layersProto.ByteSize());
            dumpAll = false;
        }

        if (numArgs) {
        if (numArgs) {
            if ((index < numArgs) &&
            if ((index < numArgs) &&
                    (args[index] == String16("--list"))) {
                    (args[index] == String16("--list"))) {
@@ -3906,11 +3909,22 @@ status_t SurfaceFlinger::doDump(int fd, const Vector<String16>& args, bool asPro
                mLayerStats.dump(result);
                mLayerStats.dump(result);
                dumpAll = false;
                dumpAll = false;
            }
            }

            if ((index < numArgs) && (args[index] == String16("--timestats"))) {
                index++;
                mTimeStats.parseArgs(asProto, args, index, result);
                dumpAll = false;
            }
        }
        }


        if (dumpAll) {
        if (dumpAll) {
            if (asProto) {
                LayersProto layersProto = dumpProtoInfo(LayerVector::StateSet::Current);
                result.append(layersProto.SerializeAsString().c_str(), layersProto.ByteSize());
            } else {
                dumpAllLocked(args, index, result);
                dumpAllLocked(args, index, result);
            }
            }
        }


        if (locked) {
        if (locked) {
            mStateLock.unlock();
            mStateLock.unlock();
Loading