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

Commit 90092f43 authored by Mikael Pessa's avatar Mikael Pessa Committed by Yiwei Zhang
Browse files

Refactor: Pull tracing out of TimeStats. 

The tracing in TimeStats ended up having no actual overlap with current
TimeStats functionality. This CL pulls all tracing related code out
into its own class.

Test: atest libsurfaceflinger_unittest and manually inspected traces.

Run trace with:
{ adb shell perfetto -c - --txt -o /data/misc/perfetto-traces/trace <<EOF
buffers: {
    size_kb: 1280
}
data_sources: {
    config {
        name: "android.surfaceflinger.frame"
    }
}
duration_ms: 3000
EOF
} && adb pull /data/misc/perfetto-traces/trace ~/Desktop/trace

Fixes: 140298240
Change-Id: I52d80d46eb8dee8979b02416ab7a758b7e58dfd1
parent 7fcea261

services/surfaceflinger/Android.bp

+1 −0
Original line number Diff line number Diff line
@@ -139,6 +139,7 @@ filegroup { 
        "DisplayHardware/VirtualDisplaySurface.cpp",

        "Effects/Daltonizer.cpp",

        "EventLog/EventLog.cpp",

        "FrameTracer/FrameTracer.cpp",

        "FrameTracker.cpp",

        "Layer.cpp",

        "LayerProtoHelper.cpp",

services/surfaceflinger/BufferLayer.cpp

+9 −6
Original line number Diff line number Diff line
@@ -51,6 +51,7 @@ 


#include "Colorizer.h"

#include "DisplayDevice.h"

#include "FrameTracer/FrameTracer.h"

#include "LayerRejecter.h"

#include "TimeStats/TimeStats.h"
@@ -71,7 +72,9 @@ BufferLayer::BufferLayer(const LayerCreationArgs& args) 


BufferLayer::~BufferLayer() {

    mFlinger->deleteTextureAsync(mTextureName);

    mFlinger->mTimeStats->onDestroy(getSequence());

    const int32_t layerID = getSequence();

    mFlinger->mTimeStats->onDestroy(layerID);

    mFlinger->mFrameTracer->onDestroy(layerID);

}



void BufferLayer::useSurfaceDamage() {
@@ -314,17 +317,17 @@ bool BufferLayer::onPostComposition(const std::optional<DisplayId>& displayId, 


    if (presentFence->isValid()) {

        mFlinger->mTimeStats->setPresentFence(layerID, mCurrentFrameNumber, presentFence);

        mFlinger->mTimeStats->traceFence(layerID, getCurrentBufferId(), mCurrentFrameNumber,

                                         presentFence, TimeStats::FrameEvent::PRESENT_FENCE);

        mFlinger->mFrameTracer->traceFence(layerID, getCurrentBufferId(), mCurrentFrameNumber,

                                           presentFence, FrameTracer::FrameEvent::PRESENT_FENCE);

        mFrameTracker.setActualPresentFence(std::shared_ptr<FenceTime>(presentFence));

    } else if (displayId && mFlinger->getHwComposer().isConnected(*displayId)) {

        // The HWC doesn't support present fences, so use the refresh

        // timestamp instead.

        const nsecs_t actualPresentTime = mFlinger->getHwComposer().getRefreshTimestamp(*displayId);

        mFlinger->mTimeStats->setPresentTime(layerID, mCurrentFrameNumber, actualPresentTime);

        mFlinger->mTimeStats->traceTimestamp(layerID, getCurrentBufferId(), mCurrentFrameNumber,

        mFlinger->mFrameTracer->traceTimestamp(layerID, getCurrentBufferId(), mCurrentFrameNumber,

                                               actualPresentTime,

                                             TimeStats::FrameEvent::PRESENT_FENCE);

                                               FrameTracer::FrameEvent::PRESENT_FENCE);

        mFrameTracker.setActualPresentTime(actualPresentTime);

    }

services/surfaceflinger/BufferQueueLayer.cpp

+13 −11
Original line number Diff line number Diff line
@@ -29,6 +29,7 @@ 
#include "LayerRejecter.h"

#include "SurfaceInterceptor.h"



#include "FrameTracer/FrameTracer.h"

#include "TimeStats/TimeStats.h"



namespace android {
@@ -48,9 +49,9 @@ void BufferQueueLayer::onLayerDisplayed(const sp<Fence>& releaseFence) { 


    // Prevent tracing the same release multiple times.

    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {

        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,

        mFlinger->mFrameTracer->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,

                                           std::make_shared<FenceTime>(releaseFence),

                                         TimeStats::FrameEvent::RELEASE_FENCE);

                                           FrameTracer::FrameEvent::RELEASE_FENCE);

        mPreviousReleasedFrameNumber = mPreviousFrameNumber;

    }

}
@@ -337,6 +338,7 @@ status_t BufferQueueLayer::updateTexImage(bool& recomputeVisibleRegions, nsecs_t 
            mQueueItems.clear();

            mQueuedFrames = 0;

            mFlinger->mTimeStats->onDestroy(layerID);

            mFlinger->mFrameTracer->onDestroy(layerID);

        }



        // Once we have hit this state, the shadow queue may no longer
@@ -366,12 +368,12 @@ status_t BufferQueueLayer::updateTexImage(bool& recomputeVisibleRegions, nsecs_t 
        uint64_t bufferID = mQueueItems[0].mGraphicBuffer->getId();

        mFlinger->mTimeStats->setAcquireFence(layerID, currentFrameNumber,

                                              mQueueItems[0].mFenceTime);

        mFlinger->mTimeStats->traceFence(layerID, bufferID, currentFrameNumber,

        mFlinger->mFrameTracer->traceFence(layerID, bufferID, currentFrameNumber,

                                           mQueueItems[0].mFenceTime,

                                         TimeStats::FrameEvent::ACQUIRE_FENCE);

                                           FrameTracer::FrameEvent::ACQUIRE_FENCE);

        mFlinger->mTimeStats->setLatchTime(layerID, currentFrameNumber, latchTime);

        mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, currentFrameNumber, latchTime,

                                             TimeStats::FrameEvent::LATCH);

        mFlinger->mFrameTracer->traceTimestamp(layerID, bufferID, currentFrameNumber, latchTime,

                                               FrameTracer::FrameEvent::LATCH);



        mQueueItems.removeAt(0);

    }
@@ -429,9 +431,9 @@ void BufferQueueLayer::latchPerFrameState( 


void BufferQueueLayer::onFrameAvailable(const BufferItem& item) {

    const int32_t layerID = getSequence();

    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());

    mFlinger->mTimeStats->traceTimestamp(layerID, item.mGraphicBuffer->getId(), item.mFrameNumber,

                                         systemTime(), TimeStats::FrameEvent::POST);

    mFlinger->mFrameTracer->traceNewLayer(layerID, getName().c_str());

    mFlinger->mFrameTracer->traceTimestamp(layerID, item.mGraphicBuffer->getId(), item.mFrameNumber,

                                           systemTime(), FrameTracer::FrameEvent::POST);



    ATRACE_CALL();

    // Add this buffer from our internal queue tracker

services/surfaceflinger/BufferStateLayer.cpp

+12 −10
Original line number Diff line number Diff line
@@ -32,6 +32,7 @@ 


#include "BufferStateLayer.h"

#include "ColorLayer.h"

#include "FrameTracer/FrameTracer.h"

#include "TimeStats/TimeStats.h"



namespace android {
@@ -90,9 +91,9 @@ void BufferStateLayer::onLayerDisplayed(const sp<Fence>& releaseFence) { 


    // Prevent tracing the same release multiple times.

    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {

        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,

        mFlinger->mFrameTracer->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,

                                           std::make_shared<FenceTime>(releaseFence),

                                         TimeStats::FrameEvent::RELEASE_FENCE);

                                           FrameTracer::FrameEvent::RELEASE_FENCE);

        mPreviousReleasedFrameNumber = mPreviousFrameNumber;

    }

}
@@ -236,9 +237,9 @@ bool BufferStateLayer::setBuffer(const sp<GraphicBuffer>& buffer, nsecs_t postTi 


    const int32_t layerID = getSequence();

    mFlinger->mTimeStats->setPostTime(layerID, mFrameNumber, getName().c_str(), postTime);

    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());

    mFlinger->mTimeStats->traceTimestamp(layerID, buffer->getId(), mFrameNumber, postTime,

                                         TimeStats::FrameEvent::POST);

    mFlinger->mFrameTracer->traceNewLayer(layerID, getName().c_str());

    mFlinger->mFrameTracer->traceTimestamp(layerID, buffer->getId(), mFrameNumber, postTime,

                                           FrameTracer::FrameEvent::POST);

    mCurrentState.desiredPresentTime = desiredPresentTime;



    if (mFlinger->mUseSmart90ForVideo) {
@@ -569,17 +570,18 @@ status_t BufferStateLayer::updateTexImage(bool& /*recomputeVisibleRegions*/, nse 
        status_t err = bindTextureImage();

        if (err != NO_ERROR) {

            mFlinger->mTimeStats->onDestroy(layerID);

            mFlinger->mFrameTracer->onDestroy(layerID);

            return BAD_VALUE;

        }

    }



    const uint64_t bufferID = getCurrentBufferId();

    mFlinger->mTimeStats->setAcquireFence(layerID, mFrameNumber, getCurrentFenceTime());

    mFlinger->mTimeStats->traceFence(layerID, bufferID, mFrameNumber, getCurrentFenceTime(),

                                     TimeStats::FrameEvent::ACQUIRE_FENCE);

    mFlinger->mFrameTracer->traceFence(layerID, bufferID, mFrameNumber, getCurrentFenceTime(),

                                       FrameTracer::FrameEvent::ACQUIRE_FENCE);

    mFlinger->mTimeStats->setLatchTime(layerID, mFrameNumber, latchTime);

    mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, mFrameNumber, latchTime,

                                         TimeStats::FrameEvent::LATCH);

    mFlinger->mFrameTracer->traceTimestamp(layerID, bufferID, mFrameNumber, latchTime,

                                           FrameTracer::FrameEvent::LATCH);



    mCurrentStateModified = false;

services/surfaceflinger/FrameTracer/FrameTracer.cpp

0 → 100644
+173 −0
Original line number Diff line number Diff line 
/*

 * Copyright 2019 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 "FrameTracer"

#define ATRACE_TAG ATRACE_TAG_GRAPHICS



#include "FrameTracer.h"



#include <android-base/stringprintf.h>



#include <algorithm>



PERFETTO_DEFINE_DATA_SOURCE_STATIC_MEMBERS(android::FrameTracer::FrameTracerDataSource);



namespace android {



void FrameTracer::initialize() {

    perfetto::TracingInitArgs args;

    args.backends = perfetto::kSystemBackend;

    perfetto::Tracing::Initialize(args);

    registerDataSource();

}



void FrameTracer::registerDataSource() {

    perfetto::DataSourceDescriptor dsd;

    dsd.set_name(kFrameTracerDataSource);

    FrameTracerDataSource::Register(dsd);

}



void FrameTracer::traceNewLayer(int32_t layerID, const std::string& layerName) {

    FrameTracerDataSource::Trace([this, layerID, &layerName](FrameTracerDataSource::TraceContext) {

        if (mTraceTracker.find(layerID) == mTraceTracker.end()) {

            std::lock_guard<std::mutex> lock(mTraceMutex);

            mTraceTracker[layerID].layerName = layerName;

        }

    });

}



void FrameTracer::traceTimestamp(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,

                                 nsecs_t timestamp, FrameEvent::BufferEventType type,

                                 nsecs_t duration) {

    FrameTracerDataSource::Trace([this, layerID, bufferID, frameNumber, timestamp, type,

                                  duration](FrameTracerDataSource::TraceContext ctx) {

        std::lock_guard<std::mutex> lock(mTraceMutex);

        if (mTraceTracker.find(layerID) == mTraceTracker.end()) {

            return;

        }



        // Handle any pending fences for this buffer.

        tracePendingFencesLocked(ctx, layerID, bufferID);



        // Complete current trace.

        traceLocked(ctx, layerID, bufferID, frameNumber, timestamp, type, duration);

    });

}



void FrameTracer::traceFence(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,

                             const std::shared_ptr<FenceTime>& fence,

                             FrameEvent::BufferEventType type, nsecs_t startTime) {

    FrameTracerDataSource::Trace([this, layerID, bufferID, frameNumber, &fence, type,

                                  startTime](FrameTracerDataSource::TraceContext ctx) {

        const nsecs_t signalTime = fence->getSignalTime();

        if (signalTime != Fence::SIGNAL_TIME_INVALID) {

            std::lock_guard<std::mutex> lock(mTraceMutex);

            if (mTraceTracker.find(layerID) == mTraceTracker.end()) {

                return;

            }



            // Handle any pending fences for this buffer.

            tracePendingFencesLocked(ctx, layerID, bufferID);



            if (signalTime != Fence::SIGNAL_TIME_PENDING) {

                traceSpanLocked(ctx, layerID, bufferID, frameNumber, type, startTime, signalTime);

            } else {

                mTraceTracker[layerID].pendingFences[bufferID].push_back(

                        {.frameNumber = frameNumber,

                         .type = type,

                         .fence = fence,

                         .startTime = startTime});

            }

        }

    });

}



void FrameTracer::tracePendingFencesLocked(FrameTracerDataSource::TraceContext& ctx,

                                           int32_t layerID, uint64_t bufferID) {

    if (mTraceTracker[layerID].pendingFences.count(bufferID)) {

        auto& pendingFences = mTraceTracker[layerID].pendingFences[bufferID];

        for (size_t i = 0; i < pendingFences.size(); ++i) {

            auto& pendingFence = pendingFences[i];



            nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;

            if (pendingFence.fence && pendingFence.fence->isValid()) {

                signalTime = pendingFence.fence->getSignalTime();

                if (signalTime == Fence::SIGNAL_TIME_PENDING) {

                    continue;

                }

            }



            if (signalTime != Fence::SIGNAL_TIME_INVALID &&

                systemTime() - signalTime < kFenceSignallingDeadline) {

                traceSpanLocked(ctx, layerID, bufferID, pendingFence.frameNumber, pendingFence.type,

                                pendingFence.startTime, signalTime);

            }



            pendingFences.erase(pendingFences.begin() + i);

            --i;

        }

    }

}



void FrameTracer::traceLocked(FrameTracerDataSource::TraceContext& ctx, int32_t layerID,

                              uint64_t bufferID, uint64_t frameNumber, nsecs_t timestamp,

                              FrameEvent::BufferEventType type, nsecs_t duration) {

    auto packet = ctx.NewTracePacket();

    packet->set_timestamp(timestamp);

    auto* event = packet->set_graphics_frame_event()->set_buffer_event();

    event->set_buffer_id(static_cast<uint32_t>(bufferID));

    event->set_frame_number(frameNumber);

    event->set_type(type);



    if (mTraceTracker.find(layerID) != mTraceTracker.end() &&

        !mTraceTracker[layerID].layerName.empty()) {

        const std::string& layerName = mTraceTracker[layerID].layerName;

        event->set_layer_name(layerName.c_str(), layerName.size());

    }



    if (duration > 0) {

        event->set_duration_ns(duration);

    }

}



void FrameTracer::traceSpanLocked(FrameTracerDataSource::TraceContext& ctx, int32_t layerID,

                                  uint64_t bufferID, uint64_t frameNumber,

                                  FrameEvent::BufferEventType type, nsecs_t startTime,

                                  nsecs_t endTime) {

    nsecs_t timestamp = endTime;

    nsecs_t duration = 0;

    if (startTime > 0 && startTime < endTime) {

        timestamp = startTime;

        duration = endTime - startTime;

    }

    traceLocked(ctx, layerID, bufferID, frameNumber, timestamp, type, duration);

}



void FrameTracer::onDestroy(int32_t layerID) {

    std::lock_guard<std::mutex> traceLock(mTraceMutex);

    mTraceTracker.erase(layerID);

}



std::string FrameTracer::miniDump() {

    std::string result = "FrameTracer miniDump:\n";

    std::lock_guard<std::mutex> lock(mTraceMutex);

    android::base::StringAppendF(&result, "Number of layers currently being traced is %zu\n",

                                 mTraceTracker.size());

    return result;

}



} // namespace android