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

Commit 2ebf4a61 authored by Treehugger Robot's avatar Treehugger Robot Committed by Android (Google) Code Review
Browse files

Merge "Add perfetto trigger for video freeze" into main

parents 228a88e9 e232a25a
Loading
Loading
Loading
Loading
+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) {
@@ -738,4 +778,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
+33 −1
Original line number Diff line number Diff line
@@ -200,6 +200,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 {
@@ -256,8 +271,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);
@@ -376,6 +394,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);
@@ -394,6 +420,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;

@@ -445,6 +474,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
+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) {
@@ -1024,4 +1074,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