Skip to content

Commit

Permalink
Adds an error log when a potential video codec stall is detected (#26)
Browse files Browse the repository at this point in the history
We have a production issue where we get infinite fast state flips
between buffering and playing after a while.
So far, investigations have allowed us to understand that the issue
seems that video frames do not get out of the codec. So after
approximately 3 mins, the playhead gets to the end of the video buffer,
so the player switches immediately to buffering. But at the same, the
buffer is full (it's not being consumed anymore) so the buffering system
flips it back to playing immediately. And that cycle is then repeated.

This PR adds a way to detect the codec stall situation, and send an
error through the logger. The app will then be able to handle the error
properly (potentially by restarting the playback automatically).

To do so, we just check if we've been waiting for a decoded buffer for a
certain time without getting any.
  • Loading branch information
SylvainMorel committed Sep 15, 2024
1 parent 180537d commit 544ae27
Show file tree
Hide file tree
Showing 4 changed files with 37 additions and 6 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -244,6 +244,9 @@ public class PlaybackException extends Exception implements Bundleable {
/** MIREGO: Caused by a network error trying to get time from the NTP server */
public static final int ERROR_CODE_NTP = 5905;

/** MIREGO: Caused by the video codec being stalled (issue under investigation) */
public static final int ERROR_CODE_VIDEO_CODEC_STALLED = 5906;

// DRM errors (6xxx).

/** Caused by an unspecified error related to DRM protection. */
Expand Down Expand Up @@ -385,6 +388,8 @@ public static String getErrorCodeName(@ErrorCode int errorCode) {
return "ERROR_CODE_AUDIO_WAITING_FOR_HEAD_POSITION_RESET";
case ERROR_CODE_NTP:
return "ERROR_CODE_NTP";
case ERROR_CODE_VIDEO_CODEC_STALLED:
return "ERROR_CODE_VIDEO_CODEC_STALLED";

default:
if (errorCode >= CUSTOM_ERROR_CODE_BASE) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -184,13 +184,14 @@ public final class Util {
public static boolean useDifferentAudioSessionIdForTunneling = false; // MIREGO ADDED
public static int ntpTimeoutMs = 5000; // MIREGO ADDED

// TEMP DEBUG STUFF
// TEMP DEBUG STUFF (to investigate an infinite buffering issue caused by what seems to be a video codec stall)
public static int videoLastFeedInputBufferStep = 0;
public static int audioLastFeedInputBufferStep = 0;
public static int videoLastDrainOutputBufferStep = 0;
public static int audioLastDrainOutputBufferStep = 0;
public static int currentQueuedInputBuffers = 0;
public static int currentProcessedOutputBuffers = 0;
public static long waitingForDecodedVideoBufferTimeMs = 0;

/** An empty long array. */
@UnstableApi public static final long[] EMPTY_LONG_ARRAY = new long[0];
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -414,11 +414,13 @@ private static String buildCustomDiagnosticInfo(int errorCode) {
private boolean needToNotifyOutputFormatChangeAfterStreamChange;

// MIREGO for logging
int dequeuedInputCount = 0;
long lastLogMs = 0;
private int dequeuedInputCount = 0;
private long lastLogMs = 0;

// MIREGO: added the following 2 functions to log and debug a specific issue (rendering pipleine stall)
// MIREGO: added the following field and 2 functions to log and debug a specific issue (rendering pipleine stall)
// MIREGO: once the issue is solved, we should get rid of that code
private boolean hasReportedRenderingStall = false;

void saveFeedInputBufferStep(int stepIndex) {
if (getTrackType() == TRACK_TYPE_AUDIO) {
Util.audioLastFeedInputBufferStep = stepIndex;
Expand Down Expand Up @@ -790,6 +792,7 @@ protected void onDisabled() {
protected void onReset() {
// MIREGO
Log.v(Log.LOG_LEVEL_VERBOSE2, TAG, "onReset() this: %s", this);
hasReportedRenderingStall = false;

try {
disableBypass();
Expand Down Expand Up @@ -2139,6 +2142,22 @@ private boolean drainOutputBuffer(long positionUs, long elapsedRealtimeUs)
}

if (outputIndex < 0) {

// MIREGO video renderer stall detection
if (getTrackType() == TRACK_TYPE_VIDEO) {

if (Util.currentProcessedOutputBuffers < Util.currentQueuedInputBuffers) {
// waiting for a decoded buffer to be available from the codec
long currentTimeMs = System.currentTimeMillis();
if (Util.waitingForDecodedVideoBufferTimeMs == 0) {
Util.waitingForDecodedVideoBufferTimeMs = currentTimeMs; // starting to wait for the decoded buffer
} else if (!hasReportedRenderingStall && currentTimeMs > Util.waitingForDecodedVideoBufferTimeMs + 7000) { // been waiting for an arbitrary while, send an error to the app
Log.e(TAG, new PlaybackException("Video codec may be stalled error", new RuntimeException(), PlaybackException.ERROR_CODE_VIDEO_CODEC_STALLED));
hasReportedRenderingStall = true;
}
}
}

// MIREGO
Log.v(Log.LOG_LEVEL_VERBOSE2, TAG, "drainOutputBuffer(type:%d) Failed dequeueOutputBufferIndex res: %d (dequeuedOutputCount: %d)",
getTrackType(), outputIndex, dequeuedOutputCount);
Expand All @@ -2157,6 +2176,11 @@ private boolean drainOutputBuffer(long positionUs, long elapsedRealtimeUs)
return false;
}

// MIREGO video renderer stall detection
if (getTrackType() == TRACK_TYPE_VIDEO) {
Util.waitingForDecodedVideoBufferTimeMs = 0; // we got a decoded buffer, reset the wait time
}

// MIREGO START
dequeuedOutputCount++;
Log.v(Log.LOG_LEVEL_VERBOSE3, TAG, "drainOutputBuffer(type:%d) presentationTime: %d dequeuedOutputCount: %d outputIndex: %d",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -734,8 +734,6 @@ protected void onStarted() {
hasNotifiedAvDesyncError = false;
hasNotifiedAvDesyncSkippedFramesError = false;
queuedFrames = 0;
Util.currentQueuedInputBuffers = 0;
Util.currentProcessedOutputBuffers = 0;

videoFrameReleaseControl.onStarted();
}
Expand Down Expand Up @@ -777,6 +775,9 @@ protected void onReset() {
if (placeholderSurface != null) {
releasePlaceholderSurface();
}
Util.currentQueuedInputBuffers = 0;
Util.currentProcessedOutputBuffers = 0;
Util.waitingForDecodedVideoBufferTimeMs = 0;
}
}

Expand Down

0 comments on commit 544ae27

Please sign in to comment.