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

Commit e9d3b005 authored by Brian Lindahl's avatar Brian Lindahl Committed by Automerger Merge Worker
Browse files

Add perfetto trigger for video freeze am: 44ac2258 

Original change: https://android-review.googlesource.com/c/platform/frameworks/av/+/2828797



Change-Id: I046f605229dfe48d453030bf95dc9db18ac663d6
Signed-off-by: default avatarAutomerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
parents 9b407576 44ac2258

media/libstagefright/VideoRenderQualityTracker.cpp

+82 −4
Original line number Diff line number Diff line
@@ -15,7 +15,11 @@ 
 */



#define LOG_TAG "VideoRenderQualityTracker"

#define ATRACE_TAG ATRACE_TAG_VIDEO



#include <utils/Log.h>

#include <utils/Trace.h>

#include <utils/Mutex.h>



#include <media/stagefright/VideoRenderQualityTracker.h>
@@ -25,8 +29,10 @@ 
#include <stdio.h>

#include <sys/time.h>



#include <android-base/macros.h>

#include <android-base/parsebool.h>

#include <android-base/parseint.h>

#include <android-base/properties.h>



namespace android {
@@ -38,6 +44,7 @@ static constexpr float FRAME_RATE_24_3_2_PULLDOWN = 


typedef VideoRenderQualityTracker::Configuration::GetServerConfigurableFlagFn

        GetServerConfigurableFlagFn;

typedef VideoRenderQualityTracker::TraceTriggerFn TraceTriggerFn;



static void getServerConfigurableFlag(GetServerConfigurableFlagFn getServerConfigurableFlagFn,

                                      char const *flagNameSuffix, bool *value) {
@@ -149,6 +156,10 @@ VideoRenderQualityTracker::Configuration 
    getFlag(judderEventMax, "judder_event_max");

    getFlag(judderEventDetailsMax, "judder_event_details_max");

    getFlag(judderEventDistanceToleranceMs, "judder_event_distance_tolerance_ms");

    getFlag(traceTriggerEnabled, "trace_trigger_enabled");

    getFlag(traceTriggerThrottleMs, "trace_trigger_throttle_ms");

    getFlag(traceMinFreezeDurationMs, "trace_minimum_freeze_duration_ms");

    getFlag(traceMaxFreezeDurationMs, "trace_maximum_freeze_duration_ms");

#undef getFlag

    return c;

}
@@ -186,15 +197,25 @@ VideoRenderQualityTracker::Configuration::Configuration() { 
    judderEventMax = 0; // enabled only when debugging

    judderEventDetailsMax = 20;

    judderEventDistanceToleranceMs = 5000; // lump judder occurrences together when 5s or less



    // Perfetto trigger configuration.

    traceTriggerEnabled = android::base::GetProperty(

        "ro.build.type", "user") != "user"; // Enabled for non-user builds for debugging.

    traceTriggerThrottleMs = 5 * 60 * 1000; // 5 mins.

    traceMinFreezeDurationMs = 400;

    traceMaxFreezeDurationMs = 1500;

}



VideoRenderQualityTracker::VideoRenderQualityTracker() : mConfiguration(Configuration()) {

VideoRenderQualityTracker::VideoRenderQualityTracker()

    : mConfiguration(Configuration()), mTraceTriggerFn(triggerTrace) {

    configureHistograms(mMetrics, mConfiguration);

    clear();

}



VideoRenderQualityTracker::VideoRenderQualityTracker(const Configuration &configuration) :

        mConfiguration(configuration) {

VideoRenderQualityTracker::VideoRenderQualityTracker(const Configuration &configuration,

                                                     const TraceTriggerFn traceTriggerFn)

    : mConfiguration(configuration),

      mTraceTriggerFn(traceTriggerFn == nullptr ? triggerTrace : traceTriggerFn) {

    configureHistograms(mMetrics, mConfiguration);

    clear();

}
@@ -231,6 +252,11 @@ void VideoRenderQualityTracker::onFrameSkipped(int64_t contentTimeUs) { 


    resetIfDiscontinuity(contentTimeUs, -1);



    if (mTraceFrameSkippedToken == -1) {

       mTraceFrameSkippedToken = contentTimeUs;

       ATRACE_ASYNC_BEGIN("Video frame(s) skipped", mTraceFrameSkippedToken);

    }



    // Frames skipped at the end of playback shouldn't be counted as skipped frames, since the

    // app could be terminating the playback. The pending count will be added to the metrics if and

    // when the next frame is rendered.
@@ -261,11 +287,25 @@ void VideoRenderQualityTracker::onFrameRendered(int64_t contentTimeUs, int64_t a 
        return;

    }



    if (mTraceFrameSkippedToken != -1) {

        ATRACE_ASYNC_END("Video frame(s) skipped", mTraceFrameSkippedToken);

        mTraceFrameSkippedToken = -1;

    }



    int64_t actualRenderTimeUs = actualRenderTimeNs / 1000;



    if (mLastRenderTimeUs != -1) {

        mRenderDurationMs += (actualRenderTimeUs - mLastRenderTimeUs) / 1000;

        int64_t frameRenderDurationMs = (actualRenderTimeUs - mLastRenderTimeUs) / 1000;

        mRenderDurationMs += frameRenderDurationMs;

        if (mConfiguration.traceTriggerEnabled

            // Threshold for visible video freeze.

            && frameRenderDurationMs >= mConfiguration.traceMinFreezeDurationMs

            // Threshold for removing long render durations which could be video pause.

            && frameRenderDurationMs < mConfiguration.traceMaxFreezeDurationMs) {

            triggerTraceWithThrottle(mTraceTriggerFn, mConfiguration, actualRenderTimeUs);

        }

    }



    // Now that a frame has been rendered, the previously skipped frames can be processed as skipped

    // frames since the app is not skipping them to terminate playback.

    for (int64_t contentTimeUs : mPendingSkippedFrameContentTimeUsList) {
@@ -736,4 +776,42 @@ bool VideoRenderQualityTracker::is32pulldown(const FrameDurationUs &durationUs, 
    return false;

}



void VideoRenderQualityTracker::triggerTraceWithThrottle(const TraceTriggerFn traceTriggerFn,

                                                         const Configuration &c,

                                                         const int64_t triggerTimeUs) {

    static int64_t lastTriggerUs = -1;

    static Mutex updateLastTriggerLock;



    Mutex::Autolock autoLock(updateLastTriggerLock);

    if (lastTriggerUs != -1) {

        int32_t sinceLastTriggerMs = int32_t((triggerTimeUs - lastTriggerUs) / 1000);

        // Throttle the trace trigger calls to reduce continuous PID fork calls in a short time

        // to impact device performance, and reduce spamming trace reports.

        if (sinceLastTriggerMs < c.traceTriggerThrottleMs) {

            ALOGI("Not triggering trace - not enough time since last trigger");

            return;

        }

    }

    lastTriggerUs = triggerTimeUs;

    (*traceTriggerFn)();

}



void VideoRenderQualityTracker::triggerTrace() {

    // Trigger perfetto to stop always-on-tracing (AOT) to collect trace into a file for video

    // freeze event, the collected trace categories are configured by AOT.

    const char* args[] = {"/system/bin/trigger_perfetto", "com.android.codec-video-freeze", NULL};

    pid_t pid = fork();

    if (pid < 0) {

        ALOGI("Failed to fork for triggering trace");

        return;

    }

    if (pid == 0) {

        // child process.

        execvp(args[0], const_cast<char**>(args));

        ALOGW("Failed to trigger trace %s", args[1]);

        _exit(1);

    }

    ALOGI("Triggered trace %s", args[1]);

}



} // namespace android

media/libstagefright/include/media/stagefright/VideoRenderQualityTracker.h

+33 −1
Original line number Diff line number Diff line
@@ -197,6 +197,21 @@ public: 
        // The maximum distance in time between two judder occurrences such that both will be

        // lumped into the same judder event.

        int32_t judderEventDistanceToleranceMs;

        //

        // Whether or not Perfetto trace trigger is enabled.

        bool traceTriggerEnabled;

        //

        // The throttle time for Perfetto trace trigger to avoid triggering multiple traces for

        // the same event in a short time.

        int32_t traceTriggerThrottleMs;

        //

        // The minimum frame render duration to recognize video freeze event to collect trace.

        int32_t traceMinFreezeDurationMs;

        //

        // The maximum frame render duration to recognize video freeze event. A frame render

        // duration that is larger than the max duration would not trigger trace collection for

        // video freeze because it's highly possible a video pause.

        int32_t traceMaxFreezeDurationMs;

    };



    struct FreezeEvent {
@@ -253,8 +268,11 @@ public: 
        Details details;

    };



    typedef void (*TraceTriggerFn)();



    VideoRenderQualityTracker();

    VideoRenderQualityTracker(const Configuration &configuration);

    VideoRenderQualityTracker(const Configuration &configuration,

                              const TraceTriggerFn traceTriggerFn = nullptr);



    // Called when a tunnel mode frame has been queued.

    void onTunnelFrameQueued(int64_t contentTimeUs);
@@ -373,6 +391,14 @@ private: 
                                        JudderEvent &e, const VideoRenderQualityMetrics & m,

                                        const Configuration &c, JudderEvent *judderEventOut);



    // Trigger trace collection for video freeze.

    static void triggerTrace();



    // Trigger collection of a Perfetto Always-On-Tracing (AOT) trace file for video freeze,

    // triggerTimeUs is used as a throttle to avoid triggering multiple traces in a short time.

    static void triggerTraceWithThrottle(TraceTriggerFn traceTriggerFn,

                                         const Configuration &c, const int64_t triggerTimeUs);



    // Check to see if a discontinuity has occurred by examining the content time and the

    // app-desired render time. If so, reset some internal state.

    bool resetIfDiscontinuity(int64_t contentTimeUs, int64_t desiredRenderTimeUs);
@@ -391,6 +417,9 @@ private: 
    // Configurable elements of the metrics algorithms.

    const Configuration mConfiguration;



    // The function for triggering trace collection for video freeze.

    const TraceTriggerFn mTraceTriggerFn;



    // Metrics are updated every time a frame event occurs - skipped, dropped, rendered.

    VideoRenderQualityMetrics mMetrics;
@@ -442,6 +471,9 @@ private: 
    // Frame durations derived from timestamps captured by the display subsystem, indicating the

    // wall clock atime at which the frame is actually rendered.

    FrameDurationUs mActualFrameDurationUs;



    // Token of async atrace for video frame dropped/skipped by the app.

    int64_t mTraceFrameSkippedToken= -1;

};



}  // namespace android

media/libstagefright/tests/VideoRenderQualityTracker_test.cpp

+122 −1
Original line number Diff line number Diff line
@@ -36,10 +36,11 @@ static constexpr float FRAME_RATE_24_3_2_PULLDOWN = 
class Helper {

public:

    Helper(double contentFrameDurationMs, const Configuration &configuration) :

            mVideoRenderQualityTracker(configuration) {

            mVideoRenderQualityTracker(configuration, testTraceTrigger) {

        mContentFrameDurationUs = int64_t(contentFrameDurationMs * 1000);

        mMediaTimeUs = 0;

        mClockTimeNs = 0;

        sTraceTriggeredCount = 0;

    }



    void changeContentFrameDuration(double contentFrameDurationMs) {
@@ -100,6 +101,10 @@ public: 
        return e;

    }



    int getTraceTriggeredCount() {

        return sTraceTriggeredCount;

    }



private:

    VideoRenderQualityTracker mVideoRenderQualityTracker;

    int64_t mContentFrameDurationUs;
@@ -107,7 +112,15 @@ private: 
    int64_t mClockTimeNs;

    VideoRenderQualityTracker::FreezeEvent mFreezeEvent;

    VideoRenderQualityTracker::JudderEvent mJudderEvent;



    static int sTraceTriggeredCount;



    static void testTraceTrigger() {

        sTraceTriggeredCount++;

    };

};



int Helper::sTraceTriggeredCount = 0;



class VideoRenderQualityTrackerTest : public ::testing::Test {

public:
@@ -139,6 +152,10 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withDefault 
    EXPECT_EQ(c.judderEventMax, d.judderEventMax);

    EXPECT_EQ(c.judderEventDetailsMax, d.judderEventDetailsMax);

    EXPECT_EQ(c.judderEventDistanceToleranceMs, d.judderEventDistanceToleranceMs);

    EXPECT_EQ(c.traceTriggerEnabled, d.traceTriggerEnabled);

    EXPECT_EQ(c.traceTriggerThrottleMs, d.traceTriggerThrottleMs);

    EXPECT_EQ(c.traceMinFreezeDurationMs, d.traceMinFreezeDurationMs);

    EXPECT_EQ(c.traceMaxFreezeDurationMs, d.traceMaxFreezeDurationMs);

}



TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withEmpty) {
@@ -166,6 +183,10 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withEmpty) 
    EXPECT_EQ(c.judderEventMax, d.judderEventMax);

    EXPECT_EQ(c.judderEventDetailsMax, d.judderEventDetailsMax);

    EXPECT_EQ(c.judderEventDistanceToleranceMs, d.judderEventDistanceToleranceMs);

    EXPECT_EQ(c.traceTriggerEnabled, d.traceTriggerEnabled);

    EXPECT_EQ(c.traceTriggerThrottleMs, d.traceTriggerThrottleMs);

    EXPECT_EQ(c.traceMinFreezeDurationMs, d.traceMinFreezeDurationMs);

    EXPECT_EQ(c.traceMaxFreezeDurationMs, d.traceMaxFreezeDurationMs);

}



TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withInvalid) {
@@ -193,6 +214,10 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withInvalid 
    EXPECT_EQ(c.judderEventMax, d.judderEventMax);

    EXPECT_EQ(c.judderEventDetailsMax, d.judderEventDetailsMax);

    EXPECT_EQ(c.judderEventDistanceToleranceMs, d.judderEventDistanceToleranceMs);

    EXPECT_EQ(c.traceTriggerEnabled, d.traceTriggerEnabled);

    EXPECT_EQ(c.traceTriggerThrottleMs, d.traceTriggerThrottleMs);

    EXPECT_EQ(c.traceMinFreezeDurationMs, d.traceMinFreezeDurationMs);

    EXPECT_EQ(c.traceMaxFreezeDurationMs, d.traceMaxFreezeDurationMs);

}



TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withAlmostValid) {
@@ -232,6 +257,14 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withAlmostV 
                return "10*10";

            } else if (flag == "render_metrics_judder_event_distance_tolerance_ms") {

                return "140-a";

            } else if (flag == "render_metrics_trace_trigger_enabled") {

                return "fals";

            } else if (flag == "render_metrics_trace_trigger_throttle_ms") {

                return "12345678901234";

            } else if (flag == "render_metrics_trace_minimum_freeze_duration_ms") {

                return "10b0";

            } else if (flag == "render_metrics_trace_maximum_freeze_duration_ms") {

                return "100a";

            }

            return "";

        }
@@ -255,6 +288,10 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withAlmostV 
    EXPECT_EQ(c.judderEventMax, d.judderEventMax);

    EXPECT_EQ(c.judderEventDetailsMax, d.judderEventDetailsMax);

    EXPECT_EQ(c.judderEventDistanceToleranceMs, d.judderEventDistanceToleranceMs);

    EXPECT_EQ(c.traceTriggerEnabled, d.traceTriggerEnabled);

    EXPECT_EQ(c.traceTriggerThrottleMs, d.traceTriggerThrottleMs);

    EXPECT_EQ(c.traceMinFreezeDurationMs, d.traceMinFreezeDurationMs);

    EXPECT_EQ(c.traceMaxFreezeDurationMs, d.traceMaxFreezeDurationMs);

}



TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withValid) {
@@ -294,6 +331,14 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withValid) 
                return "10000";

            } else if (flag == "render_metrics_judder_event_distance_tolerance_ms") {

                return "11000";

            } else if (flag == "render_metrics_trace_trigger_enabled") {

                return "true";

            } else if (flag == "render_metrics_trace_trigger_throttle_ms") {

                return "50000";

            } else if (flag == "render_metrics_trace_minimum_freeze_duration_ms") {

                return "1000";

            } else if (flag == "render_metrics_trace_maximum_freeze_duration_ms") {

                return "5000";

            }

            return "";

        }
@@ -353,6 +398,11 @@ TEST_F(VideoRenderQualityTrackerTest, getFromServerConfigurableFlags_withValid) 
    EXPECT_NE(c.judderEventDetailsMax, d.judderEventDetailsMax);

    EXPECT_EQ(c.judderEventDistanceToleranceMs, 11000);

    EXPECT_NE(c.judderEventDistanceToleranceMs, d.judderEventDistanceToleranceMs);



    EXPECT_EQ(c.traceTriggerEnabled, true);

    EXPECT_EQ(c.traceTriggerThrottleMs, 50000);

    EXPECT_EQ(c.traceMinFreezeDurationMs, 1000);

    EXPECT_EQ(c.traceMaxFreezeDurationMs, 5000);

}



TEST_F(VideoRenderQualityTrackerTest, countsReleasedFrames) {
@@ -1060,4 +1110,75 @@ TEST_F(VideoRenderQualityTrackerTest, capturesOverallJudderScore) { 
    EXPECT_EQ(h.getMetrics().judderScore, 10 + 300 + 2000);

}



TEST_F(VideoRenderQualityTrackerTest,

       freezesForTraceDuration_withThrottle_throttlesTraceTrigger) {

    Configuration c;

    c.enabled = true;

    c.traceTriggerEnabled = true; // The trigger is enabled, so traces should be triggered.

    // The value of traceTriggerThrottleMs must be larger than traceMinFreezeDurationMs. Otherwise,

    // the throttle does work.

    c.traceTriggerThrottleMs = 200;

    c.traceMinFreezeDurationMs = 40;

    int32_t freeze = c.traceMinFreezeDurationMs;



    Helper h(20, c);

    // Freeze triggers separated by 80ms which is less than the threshold.

    h.render({

        freeze, // Freeze duration does not check trace trigger.

        20,     // Trace triggered.

        20,     // Throttle time:  20/200ms

        20,     // Throttle time:  40/200ms

        freeze, // Throttle time:  80/200ms

        20,     // Throttle time: 100/200ms (Trace not triggered)

    });

    EXPECT_EQ(h.getTraceTriggeredCount(), 1);

    // Next freeze trigger is separated by 200ms which breaks the throttle threshold.

    h.render({

        20,     // Throttle time: 120/200ms

        20,     // Throttle time: 140/200ms

        20,     // Throttle time: 160/200ms

        freeze, // Throttle time: 200/200ms

        20,     // Trace triggered.

    });

    EXPECT_EQ(h.getTraceTriggeredCount(), 2);

    // Next freeze trigger is separated by 80ms which is less than the threshold.

    h.render({

        20,     // Throttle time:  20/200ms

        20,     // Throttle time:  40/200ms

        freeze, // Throttle time:  80/200ms

        20,     // Throttle time: 100/200ms (Trace not triggered)

    });

    EXPECT_EQ(h.getTraceTriggeredCount(), 2);

}



TEST_F(VideoRenderQualityTrackerTest, freezeForTraceDuration_triggersTrace) {

    Configuration c;

    c.enabled = true;

    c.traceTriggerEnabled = true; // The trigger is enabled, so traces should be triggered.

    c.traceTriggerThrottleMs = 0; // Disable throttle in the test case.

    int32_t freeze1 = c.traceMinFreezeDurationMs;

    int32_t freeze2 = c.traceMaxFreezeDurationMs - 1;

    int32_t couldBeAPause = c.traceMaxFreezeDurationMs + 1;



    Helper h(20, c);

    h.render({freeze1, 20, freeze2, 20, couldBeAPause, 20});



    EXPECT_EQ(h.getTraceTriggeredCount(), 2);

}



TEST_F(VideoRenderQualityTrackerTest,

       freezeForTraceDuration_withTraceDisabled_doesNotTriggerTrace) {

    Configuration c;

    c.enabled = true;

    c.traceTriggerEnabled = false; // The trigger is disabled, so no traces should be triggered.

    c.traceTriggerThrottleMs = 0; // Disable throttle in the test case.

    int32_t freeze1 = c.traceMinFreezeDurationMs;

    int32_t freeze2 = c.traceMaxFreezeDurationMs - 1;

    int32_t couldBeAPause = c.traceMaxFreezeDurationMs + 1;



    Helper h(20, c);

    h.render({freeze1, 20, freeze2, 20, couldBeAPause, 20});



    EXPECT_EQ(h.getTraceTriggeredCount(), 0);

}

} // android