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

Commit 2b796dab authored by Nataniel Borges's avatar Nataniel Borges
Browse files

Move SF trace logging into a separate thread 

SF trace logging currently happens on the main thread, which affects
performance. Move it to a separate thread to mitigate the overhead.

Use a lock to prevent the drawing state to be updated while it is being
dumped.

Also, allow the buffer size for SF traces to be configured. Current buffer
size is fixed to 100MB, which is unfeasible for phones with lower resources.

Created option 1029 to manually update the buffer size.
To trigger the option use:
- adb shell su root service call SurfaceFlinger 1029 i32 <SIZE>

This option trigger an "Invalid Argument" error if it receives a
negative value.

Finally, just log Winscope trace if visible regions are dirty. SF
currently logs all Winscope frames. It should log only if there is a
change to mitigate resource consumption.

Test: Flash a device. Start a trace. Run systrace. Record a trace. Check
if the `commitTransaction` trace happens in a separate SF thread and
doesn't block the critical path

Change-Id: Ie05ad5c025a185b28209bbc5d26655ba9ff9042b
parent c16140fd

services/surfaceflinger/SurfaceFlinger.cpp

+58 −17
Original line number Diff line number Diff line
@@ -274,6 +274,7 @@ SurfaceFlinger::SurfaceFlinger(surfaceflinger::Factory& factory, 
        mDebugInTransaction(0),

        mLastTransactionTime(0),

        mForceFullDamage(false),

        mTracing(*this),

        mTimeStats(factory.createTimeStats()),

        mRefreshStartTime(0),

        mHasPoweredOff(false),
@@ -1671,7 +1672,6 @@ void SurfaceFlinger::handleMessageRefresh() { 
        doComposition(display, repaintEverything);

    }



    doTracing("handleRefresh");

    logLayerStats();



    postFrame();
@@ -1700,6 +1700,9 @@ bool SurfaceFlinger::handleMessageInvalidate() { 


    if (mVisibleRegionsDirty) {

        computeLayerBounds();

        if (mTracingEnabled) {

            mTracing.notify("visibleRegionsDirty");

        }

    }



    for (auto& layer : mLayersPendingRefresh) {
@@ -1838,14 +1841,6 @@ void SurfaceFlinger::doDebugFlashRegions(const sp<DisplayDevice>& displayDevice, 
    prepareFrame(displayDevice);

}



void SurfaceFlinger::doTracing(const char* where) {

    ATRACE_CALL();

    ATRACE_NAME(where);

    if (CC_UNLIKELY(mTracing.isEnabled())) {

        mTracing.traceLayers(where, dumpProtoInfo(LayerVector::StateSet::Drawing));

    }

}



void SurfaceFlinger::logLayerStats() {

    ATRACE_CALL();

    if (CC_UNLIKELY(mLayerStats.isEnabled())) {
@@ -2920,18 +2915,39 @@ void SurfaceFlinger::commitTransaction() 
    // we composite should be considered an animation as well.

    mAnimCompositionPending = mAnimTransactionPending;



    withTracingLock([&]() {

        mDrawingState = mCurrentState;

        // clear the "changed" flags in current state

        mCurrentState.colorMatrixChanged = false;



    mDrawingState.traverseInZOrder([](Layer* layer) {

        layer->commitChildList();

        mDrawingState.traverseInZOrder([](Layer* layer) { layer->commitChildList(); });

    });



    mTransactionPending = false;

    mAnimTransactionPending = false;

    mTransactionCV.broadcast();

}



void SurfaceFlinger::withTracingLock(std::function<void()> lockedOperation) {

    if (mTracingEnabledChanged) {

        mTracingEnabled = mTracing.isEnabled();

        mTracingEnabledChanged = false;

    }



    // Synchronize with Tracing thread

    std::unique_lock<std::mutex> lock;

    if (mTracingEnabled) {

        lock = std::unique_lock<std::mutex>(mDrawingStateLock);

    }



    lockedOperation();



    // Synchronize with Tracing thread

    if (mTracingEnabled) {

        lock.unlock();

    }

}



void SurfaceFlinger::computeVisibleRegions(const sp<const DisplayDevice>& displayDevice,

                                           Region& outDirtyRegion, Region& outOpaqueRegion) {

    ATRACE_CALL();
@@ -5080,13 +5096,24 @@ status_t SurfaceFlinger::onTransact(uint32_t code, const Parcel& data, Parcel* r 
                n = data.readInt32();

                if (n) {

                    ALOGD("LayerTracing enabled");

                    Mutex::Autolock lock(mStateLock);

                    mTracingEnabledChanged = true;

                    mTracing.enable();

                    doTracing("tracing.enable");

                    reply->writeInt32(NO_ERROR);

                } else {

                    ALOGD("LayerTracing disabled");

                    status_t err = mTracing.disable();

                    reply->writeInt32(err);

                    bool writeFile = false;

                    {

                        Mutex::Autolock lock(mStateLock);

                        mTracingEnabledChanged = true;

                        writeFile = mTracing.disable();

                    }



                    if (writeFile) {

                        reply->writeInt32(mTracing.writeToFile());

                    } else {

                        reply->writeInt32(NO_ERROR);

                    }

                }

                return NO_ERROR;

            }
@@ -5125,6 +5152,20 @@ status_t SurfaceFlinger::onTransact(uint32_t code, const Parcel& data, Parcel* r 
                reply->writeBool(getHwComposer().isUsingVrComposer());

                return NO_ERROR;

            }

            // Set buffer size for SF tracing (value in KB)

            case 1029: {

                n = data.readInt32();

                if (n <= 0 || n > MAX_TRACING_MEMORY) {

                    ALOGW("Invalid buffer size: %d KB", n);

                    reply->writeInt32(BAD_VALUE);

                    return BAD_VALUE;

                }



                ALOGD("Updating trace buffer to %d KB", n);

                mTracing.setBufferSize(n * 1024);

                reply->writeInt32(NO_ERROR);

                return NO_ERROR;

            }

            // Is device color managed?

            case 1030: {

                reply->writeBool(useColorManagement);

services/surfaceflinger/SurfaceFlinger.h

+9 −2
Original line number Diff line number Diff line
@@ -367,6 +367,7 @@ private: 
    friend class BufferStateLayer;

    friend class MonitoredProducer;

    friend class RegionSamplingThread;

    friend class SurfaceTracing;



    // For unit tests

    friend class TestableSurfaceFlinger;
@@ -376,6 +377,7 @@ private: 
    enum { LOG_FRAME_STATS_PERIOD =  30*60*60 };



    static const size_t MAX_LAYERS = 4096;

    static const int MAX_TRACING_MEMORY = 100 * 1024 * 1024; // 100MB



    // We're reference counted, never destroy SurfaceFlinger directly

    virtual ~SurfaceFlinger();
@@ -580,7 +582,7 @@ private: 
    uint32_t setTransactionFlags(uint32_t flags);

    uint32_t setTransactionFlags(uint32_t flags, Scheduler::TransactionStart transactionStart);

    void latchAndReleaseBuffer(const sp<Layer>& layer);

    void commitTransaction();

    void commitTransaction() REQUIRES(mStateLock);

    bool containsAnyInvalidClientState(const Vector<ComposerState>& states);

    bool transactionIsReadyToBeApplied(int64_t desiredPresentTime,

                                       const Vector<ComposerState>& states);
@@ -774,7 +776,6 @@ private: 
    void prepareFrame(const sp<DisplayDevice>& display);

    void doComposition(const sp<DisplayDevice>& display, bool repainEverything);

    void doDebugFlashRegions(const sp<DisplayDevice>& display, bool repaintEverything);

    void doTracing(const char* where);

    void logLayerStats();

    void doDisplayComposition(const sp<DisplayDevice>& display, const Region& dirtyRegion);
@@ -891,6 +892,7 @@ private: 
    void dumpDisplayIdentificationData(std::string& result) const;

    void dumpWideColorInfo(std::string& result) const;

    LayersProto dumpProtoInfo(LayerVector::StateSet stateSet) const;

    void withTracingLock(std::function<void()> operation) REQUIRES(mStateLock);

    LayersProto dumpVisibleLayersProtoInfo(const sp<DisplayDevice>& display) const;



    bool isLayerTripleBufferingDisabled() const {
@@ -932,6 +934,9 @@ private: 
    bool mAnimTransactionPending;

    SortedVector< sp<Layer> > mLayersPendingRemoval;



    // guards access to the mDrawing state if tracing is enabled.

    mutable std::mutex mDrawingStateLock;



    // global color transform states

    Daltonizer mDaltonizer;

    float mGlobalSaturationFactor = 1.0f;
@@ -1010,6 +1015,8 @@ private: 
    bool mPropagateBackpressure = true;

    std::unique_ptr<SurfaceInterceptor> mInterceptor{mFactory.createSurfaceInterceptor(this)};

    SurfaceTracing mTracing;

    bool mTracingEnabled = false;

    bool mTracingEnabledChanged GUARDED_BY(mStateLock) = false;

    LayerStats mLayerStats;

    std::shared_ptr<TimeStats> mTimeStats;

    bool mUseHwcVirtualDisplays = false;

services/surfaceflinger/SurfaceTracing.cpp

+81 −24
Original line number Diff line number Diff line
@@ -18,6 +18,7 @@ 
#define ATRACE_TAG ATRACE_TAG_GRAPHICS



#include "SurfaceTracing.h"

#include <SurfaceFlinger.h>



#include <android-base/file.h>

#include <android-base/stringprintf.h>
@@ -27,6 +28,48 @@ 


namespace android {



void SurfaceTracing::mainLoop() {

    bool enabled = true;

    // Upon activation, logs the first frame

    traceLayers("tracing.enable");

    do {

        std::unique_lock<std::mutex> sfLock(mFlinger.mDrawingStateLock);

        mConditionalVariable.wait(sfLock);

        LayersTraceProto entry = traceLayersLocked(mWhere);

        sfLock.unlock();

        {

            std::scoped_lock bufferLock(mTraceLock);

            mBuffer.emplace(std::move(entry));

            if (mWriteToFile) {

                writeProtoFileLocked();

                mWriteToFile = false;

            }



            enabled = mEnabled;

        }

    } while (enabled);

}



void SurfaceTracing::traceLayers(const char* where) {

    std::unique_lock<std::mutex> sfLock(mFlinger.mDrawingStateLock);

    LayersTraceProto entry = traceLayersLocked(where);

    sfLock.unlock();

    std::scoped_lock bufferLock(mTraceLock);

    mBuffer.emplace(std::move(entry));

}



void SurfaceTracing::notify(const char* where) {

    std::lock_guard<std::mutex> sfLock(mFlinger.mDrawingStateLock);

    mWhere = strdup(where);

    mConditionalVariable.notify_one();

}



void SurfaceTracing::writeToFileAsync() {

    std::lock_guard<std::mutex> bufferLock(mTraceLock);

    mWriteToFile = true;

    mConditionalVariable.notify_one();

}



void SurfaceTracing::LayersTraceBuffer::reset(size_t newSize) {

    // use the swap trick to make sure memory is released

    std::queue<LayersTraceProto>().swap(mStorage);
@@ -58,50 +101,60 @@ void SurfaceTracing::LayersTraceBuffer::flush(LayersTraceFileProto* fileProto) { 
    }

}



void SurfaceTracing::enable(size_t bufferSizeInByte) {

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

void SurfaceTracing::enable() {

    std::lock_guard<std::mutex> bufferLock(mTraceLock);



    if (mEnabled) {

        return;

    }



    mBuffer.reset(mBufferSize);

    mEnabled = true;

    mBuffer.reset(bufferSizeInByte);

    mThread = std::thread(&SurfaceTracing::mainLoop, this);

}



status_t SurfaceTracing::disable() {

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

status_t SurfaceTracing::writeToFile() {

    mThread.join();

    return mLastErr;

}



bool SurfaceTracing::disable() {

    std::lock_guard<std::mutex> bufferLock(mTraceLock);



    if (!mEnabled) {

        return NO_ERROR;

        return false;

    }



    mEnabled = false;

    status_t err(writeProtoFileLocked());

    ALOGE_IF(err == PERMISSION_DENIED, "Could not save the proto file! Permission denied");

    ALOGE_IF(err == NOT_ENOUGH_DATA, "Could not save the proto file! There are missing fields");

    mBuffer.reset(0);

    return err;

    mWriteToFile = true;

    mConditionalVariable.notify_all();

    return true;

}



bool SurfaceTracing::isEnabled() const {

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

    std::lock_guard<std::mutex> bufferLock(mTraceLock);

    return mEnabled;

}



void SurfaceTracing::traceLayers(const char* where, LayersProto layers) {

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

    if (!mEnabled) {

        return;

void SurfaceTracing::setBufferSize(size_t bufferSizeInByte) {

    std::lock_guard<std::mutex> bufferLock(mTraceLock);

    mBufferSize = bufferSizeInByte;

    mBuffer.setSize(bufferSizeInByte);

}



LayersTraceProto SurfaceTracing::traceLayersLocked(const char* where) {

    ATRACE_CALL();



    LayersTraceProto entry;

    entry.set_elapsed_realtime_nanos(elapsedRealtimeNano());

    entry.set_where(where);

    LayersProto layers(mFlinger.dumpProtoInfo(LayerVector::StateSet::Drawing));

    entry.mutable_layers()->Swap(&layers);



    mBuffer.emplace(std::move(entry));

    return entry;

}



status_t SurfaceTracing::writeProtoFileLocked() {

void SurfaceTracing::writeProtoFileLocked() {

    ATRACE_CALL();



    LayersTraceFileProto fileProto;
@@ -110,19 +163,23 @@ status_t SurfaceTracing::writeProtoFileLocked() { 
    fileProto.set_magic_number(uint64_t(LayersTraceFileProto_MagicNumber_MAGIC_NUMBER_H) << 32 |

                               LayersTraceFileProto_MagicNumber_MAGIC_NUMBER_L);

    mBuffer.flush(&fileProto);

    mBuffer.reset(mBufferSize);



    if (!fileProto.SerializeToString(&output)) {

        return PERMISSION_DENIED;

        ALOGE("Could not save the proto file! Permission denied");

        mLastErr = PERMISSION_DENIED;

    }

    if (!android::base::WriteStringToFile(output, kDefaultFileName, true)) {

        return PERMISSION_DENIED;

    if (!android::base::WriteStringToFile(output, kDefaultFileName, S_IRWXU | S_IRGRP, getuid(),

                                          getgid(), true)) {

        ALOGE("Could not save the proto file! There are missing fields");

        mLastErr = PERMISSION_DENIED;

    }



    return NO_ERROR;

    mLastErr = NO_ERROR;

}



void SurfaceTracing::dump(std::string& result) const {

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

    std::lock_guard<std::mutex> bufferLock(mTraceLock);



    base::StringAppendF(&result, "Tracing state: %s\n", mEnabled ? "enabled" : "disabled");

    base::StringAppendF(&result, "  number of entries: %zu (%.2fMB / %.2fMB)\n",

services/surfaceflinger/SurfaceTracing.h

+31 −10
Original line number Diff line number Diff line
@@ -18,30 +18,38 @@ 


#include <layerproto/LayerProtoHeader.h>

#include <utils/Errors.h>

#include <utils/StrongPointer.h>



#include <android-base/thread_annotations.h>

#include <condition_variable>

#include <memory>

#include <mutex>

#include <queue>

#include <thread>



using namespace android::surfaceflinger;



namespace android {



class SurfaceFlinger;



constexpr auto operator""_MB(unsigned long long const num) {

    return num * 1024 * 1024;

}



/*

 * SurfaceTracing records layer states during surface flinging.

 */

class SurfaceTracing {

public:

    void enable() { enable(kDefaultBufferCapInByte); }

    void enable(size_t bufferSizeInByte);

    status_t disable();

    void traceLayers(const char* where, LayersProto);



    SurfaceTracing(SurfaceFlinger& flinger) : mFlinger(flinger) {}

    void enable();

    bool disable();

    status_t writeToFile();

    bool isEnabled() const;

    void notify(const char* where);



    void setBufferSize(size_t bufferSizeInByte);

    void writeToFileAsync();

    void dump(std::string& result) const;



private:
@@ -54,6 +62,7 @@ private: 
        size_t used() const { return mUsedInBytes; }

        size_t frameCount() const { return mStorage.size(); }



        void setSize(size_t newSize) { mSizeInBytes = newSize; }

        void reset(size_t newSize);

        void emplace(LayersTraceProto&& proto);

        void flush(LayersTraceFileProto* fileProto);
@@ -64,11 +73,23 @@ private: 
        std::queue<LayersTraceProto> mStorage;

    };



    status_t writeProtoFileLocked();

    void mainLoop();

    void traceLayers(const char* where);

    LayersTraceProto traceLayersLocked(const char* where);

    void writeProtoFileLocked() REQUIRES(mTraceLock);



    const SurfaceFlinger& mFlinger;



    char* mWhere;

    status_t mLastErr = NO_ERROR;

    std::thread mThread;

    std::condition_variable mConditionalVariable;

    mutable std::mutex mTraceLock;



    bool mEnabled = false;

    mutable std::mutex mTraceMutex;

    LayersTraceBuffer mBuffer;

    LayersTraceBuffer mBuffer GUARDED_BY(mTraceLock);

    size_t mBufferSize GUARDED_BY(mTraceLock) = kDefaultBufferCapInByte;

    bool mEnabled GUARDED_BY(mTraceLock) = false;

    bool mWriteToFile GUARDED_BY(mTraceLock) = false;

};



} // namespace android