Burst of invalid frame renders on seek with Android 10 AmLogic

[stevemayhew]

ExoPlayer Version

2.18.0

Devices that reproduce the issue

Google ChormeCast With Google TV running Android 10, many other AmLogic based devices.

Devices that do not reproduce the issue

AmLogic based devices running Android 9.

Reproducible in the demo app?

Yes

Reproduction steps

1. Play the content (adb shell am start -n com.google.android.exoplayer2.demo/.PlayerActivity -a com.google.android.exoplayer.demo.action.VIEW -d ...)
2. Seek to a position mid-segment: (adb shell am start -n com.google.android.exoplayer2.demo/.PlayerActivity -a com.google.android.exoplayer.action.SEEK_TO --ei position 279000

You can add the SEEK_TO intent with this simple code in PlayerActivity

  @Override
  public void onNewIntent(Intent intent) {
    super.onNewIntent(intent);
    String action = intent.getAction();
    if ("com.google.android.exoplayer.action.SEEK_TO".equals(action)) {
        long seekTo =  intent.getIntExtra("position", C.POSITION_UNSET);
        player.seekTo(seekTo);
    } else {
      releasePlayer();
      releaseClientSideAdsLoader();
      clearStartPosition();
      setIntent(intent);
    }
  }

Note, for hardware I am using:

1. Google Chromecast with Google TV (GZRNL)
2. An LG webPS TV IF7600 (any 60hz refresh 4k monitor seems to reproduce this)

Expected result

Playback starts almost immediately after the seek with no frame glitches or drops.

Actual result

Over 100 frame drops, 50+ consecutive. These are the result of frames that should have been marked for discard (decodeOnlyPresentationTimestamps) are not discarded.

Our working assumption is that AmLogic has added some kind of frame-rate matching adjustment that causes double the frames on decode (e.g. 29.9 FPS conversion to 60hz display refresh) as was fixed for Nvidia in this commit https://github.com/google/ExoPlayer/commit/ee1ec8d3d6c89dfa11ca5504fd4eae919fcd83ac

The auto-src flag does not work however to turn this off.

Media

Will send via email.

Bug Report

• [ ] You will email the zip file produced by adb bugreport to dev.exoplayer@gmail.com after filing this issue.

[stevemayhew]

@tonihei Here's some note and comments from our internal bug with Evolution for this...

I believe this issue is:

1. A platform (AmLogic firmware) issue
2. Triggered by 1080p resolution
3. Related to the frame rate up-conversion performed by the CODEC

Comment 1

We are not re-producing this on our headend I believe because the highest resolution track is 1280x720:

  Duration: N/A, start: 29843.684211, bitrate: N/A
  Program 0
    Metadata:
      variant_bitrate : 0
  Stream #0:0: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p(tv, bt709), 1280x720 [SAR 1:1 DAR 16:9], Closed Captions, 29.97 fps, 29.97 tbr, 90k tbn, 59.94 tbc
    Metadata:
      variant_bitrate : 0

But the customer's highest resolution is 1080:

  Duration: 00:08:18.50, start: 67529.484622, bitrate: 0 kb/s
  Program 0
    Metadata:
      variant_bitrate : 0
  Stream #0:0: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p(tv, bt709), 1920x1080 [SAR 1:1 DAR 16:9], Closed Captions, 29.97 fps, 29.97 tbr, 90k tbn, 59.94 tbc
    Metadata:
      variant_bitrate : 0

I am on a 4k LG TV with 60Hz refresh rate.  The problem is significantly worse if I set the TV to 4k2k-23.976hz refresh rate, my current suspension is there is platform bug (with the AmLogic based boxes) running Android 10 related to VSYNC and frame rate conversion (decoder is producing 60fps frames for the 1080p@29.97, for the 1280x720 variant it is not doing this) that is causing this rendering artifact on seek (or channel change).

Comment 2

On our local headend we have a stream from the NASA channel encoded for 1080p, it does not show this problem. There are a few notable differences in the encoding we have vs what LLA's 13 News channel has. Both are High profile and 1920x1080 format. The encoding differences are as follows:

Value	News 13 Setting	NASA setting
level	4.0	4.2
frame_rate	29.97	59.94
has_b_frames	3	1

The first two are pretty self explanatory, has_b_frames refers to how the B frames are ordered in the stream vs their presentation order. This one is interesting, as I see B frames in the New 13 stream that are far before their actual presentation time.

[tonihei]

In https://github.com/google/ExoPlayer/commit/ee1ec8d3d6c89dfa11ca5504fd4eae919fcd83ac#commitcomment-78605657 you mentioned that you have a pending investigation with AmLogic about this. Does it make sense to wait for this investigation? Ideally, we can disable this behavior directly instead of working around it.

[stevemayhew]

Does it make sense to wait for this investigation?

Somewhat, would greatly appreciate any investigation your team can do as well with SEI / AmLogic, as they supply you for Chromecast (and the Google device has the same issue). Suspect Google might have a bit more leverage with the vendor.

Also, if you could check with the MediaCodec team about auto-frc, this is how the issue was fixed for NVIDIA Shield but it looks like this is a temporary feature from this comment: https://cs.android.com/android/platform/superproject/+/master:frameworks/av/media/libstagefright/ACodec.cpp;l=1938?q=auto-frc

I will share everything we hear from the case in this bug from SEI and/or AmLogic.. Also, I wanted a place to share with you an easy set of steps to reproduce it once we have a fix.

Ideally, we can disable this behavior directly instead of working around it.

I agree, hopefully something like auto-frc or similar can be set to turn it off. You can check this with @ojw28 , but my understanding is the VSYNC matching code in VideoFrameReleaseHelper already handles matching frame-rate to monitor refresh rate eliminating tearing and shudder issues without help from the codec. In addition doubling decoded frames from 30 to 60 fps adds significantly to the CPU load. If the codec chose to do this in tunneled mode that would be one thing, but in non-tunneled it is just a burden.

[icbaker]

Actual result

Over 100 frame drops, 50+ consecutive. These are the result of frames that should have been marked for discard (decodeOnlyPresentationTimestamps) are not discarded.

Our working assumption is that AmLogic has added some kind of frame-rate matching adjustment that causes double the frames on decode (e.g. 29.9 FPS conversion to 60hz display refresh) as was fixed for Nvidia in this commit ee1ec8d

I'm able to reproduce the problem on a Chromecast with Google TV using the instructions provided.

However I haven't been able to completely validate this theory yet. I did the following:

1. At the top of MediaCodecRenderer.isDecodeOnlyBuffer, I logged the current (decode-side) timestamps, as well as the contents of decodeOnlyPresentationTimestamps for the first 100 frames after onPositionReset (i.e. a seek):

   if (buffersToPrintAfterPositionReset > 0) {
     buffersToPrintAfterPositionReset--;
     Log.w("ibaker", "decoded timestamp: " + presentationTimeUs);
     Log.w("ibaker", "Unmatched decode-only timestamps: " + decodeOnlyPresentationTimestamps);
   }

   • I saw roughly what I expected: After a seek the decodeOnlyPresentationTimestamps list has lots of entries, then each time a 'decode-only' timestamp arrives it matches the list and is removed. The list soon ends up empty. This shows the decoder is not 'modifying' buffer timestamps (like we've seen in some mp3 decoders), because if it was then the list would never get empty.

2. In order to detect the codec duplicating frames (where only one would match the decode-only list), I also created a parallel list of decode-only timestamps that is append-only. I added some logging in MediaCodecRenderer.isDecodeOnlyBuffer if we find a timestamp that is in the append-only list, but not in the 'normal' list (this would be a duplicate frame the codec has created). This logging never fired.

Am I looking for the wrong kind of timestamp modifications?

[icbaker]

One thing I did notice (not sure if this is obvious or expected): MediaCodecRenderer.resetCodecStateForFlush is called during the stuttering/frame dropping.

This clears the list of decodeOnlyPresentationTimestamps (which is why I spotted it, because initially my 'append only' list was being cleared here too). Clearing this list seems correct to me (naively) because we've already flushed the codec, so all buffers are invalidated at this point. So I don't think this is an issue.

[stevemayhew]

@icbaker The decoder is producing 2 for 1 output frames (each input buffer produces two decoded frames. So the timestamps don't exists for half of the frames (as there was no input to match).

We are working our channels (would appreciate your channels too!) to AmLogic to find out if they have implemented something like NVIDIA Shield FRC logic in the Android 10 platforms AmLogic Awesome decoder. It certainly appears this is so, and if so we need a way to disable it like the NVIDIA. I tried the code from that commit (set auto-frc) but it did not work with AmLogic.

[stevemayhew]

@tonihei I reviewed the pull request #10468 and tested the code, while it is sort of on a possible correct path... It has issues so it does not fix this bug.

[icbaker]

@stevemayhew Ah right, thanks for clarifying and sorry I was looking in slightly the wrong place before. I'm now able to clearly log what you're seeing. After a seek I logged the first 100 (decoded) buffers being evaluated by MediaCodecRenderer.isDecodeOnlyBuffer and I see that it alternates true/false while passing through the 'decode only' section of content - which is explained by the codec interpolating frames in between the buffers we pass in.

2022-08-02 12:29:05.032  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278244667, decodeOnly=true
2022-08-02 12:29:05.040  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278261344, decodeOnly=false
2022-08-02 12:29:05.042  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278278033, decodeOnly=true
2022-08-02 12:29:05.054  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278294710, decodeOnly=false
2022-08-02 12:29:05.061  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278311400, decodeOnly=true
2022-08-02 12:29:05.063  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278328077, decodeOnly=false
2022-08-02 12:29:05.088  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278344767, decodeOnly=true
2022-08-02 12:29:05.089  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278361444, decodeOnly=false
2022-08-02 12:29:05.091  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278378133, decodeOnly=true
2022-08-02 12:29:05.093  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278394810, decodeOnly=false
2022-08-02 12:29:05.097  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278411500, decodeOnly=true
2022-08-02 12:29:05.112  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278428177, decodeOnly=false
2022-08-02 12:29:05.113  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278444867, decodeOnly=true
2022-08-02 12:29:05.114  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278461544, decodeOnly=false
2022-08-02 12:29:05.117  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278478233, decodeOnly=true
2022-08-02 12:29:05.123  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278494910, decodeOnly=false
2022-08-02 12:29:05.134  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278511600, decodeOnly=true
2022-08-02 12:29:05.135  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278528277, decodeOnly=false
2022-08-02 12:29:05.138  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278544967, decodeOnly=true
2022-08-02 12:29:05.144  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278561644, decodeOnly=false
2022-08-02 12:29:05.155  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278578333, decodeOnly=true
2022-08-02 12:29:05.156  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278595010, decodeOnly=false
2022-08-02 12:29:05.157  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278611700, decodeOnly=true
2022-08-02 12:29:05.165  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278628377, decodeOnly=false
2022-08-02 12:29:05.166  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278645067, decodeOnly=true
2022-08-02 12:29:05.174  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278661744, decodeOnly=false
2022-08-02 12:29:05.176  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278678433, decodeOnly=true
2022-08-02 12:29:05.189  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278695110, decodeOnly=false
2022-08-02 12:29:05.192  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278711800, decodeOnly=true
2022-08-02 12:29:05.193  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278728477, decodeOnly=false
2022-08-02 12:29:05.197  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278745167, decodeOnly=true
2022-08-02 12:29:05.216  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278761844, decodeOnly=false
2022-08-02 12:29:05.217  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278778533, decodeOnly=true
2022-08-02 12:29:05.218  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278795210, decodeOnly=false
2022-08-02 12:29:05.220  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278811900, decodeOnly=true
2022-08-02 12:29:05.226  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278828577, decodeOnly=false
2022-08-02 12:29:05.235  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278845267, decodeOnly=true
2022-08-02 12:29:05.237  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278861944, decodeOnly=false
2022-08-02 12:29:05.245  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278878633, decodeOnly=true
2022-08-02 12:29:05.248  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278895310, decodeOnly=false
2022-08-02 12:29:05.250  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278912000, decodeOnly=true
2022-08-02 12:29:05.265  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278928677, decodeOnly=false
2022-08-02 12:29:05.267  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278945367, decodeOnly=true
2022-08-02 12:29:05.268  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278962044, decodeOnly=false
2022-08-02 12:29:05.276  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278978733, decodeOnly=true
2022-08-02 12:29:05.277  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000278995410, decodeOnly=false
2022-08-02 12:29:05.286  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000279012100, decodeOnly=false
2022-08-02 12:29:05.288  8120-8468  ibaker                  androidx.media3.demo.main            W  Buffer t=1000279028777, decodeOnly=false

[icbaker]

I think that a decoder is not allowed to create additional output buffers. The MediaCodec javadoc seems to make it pretty clear there's a 1:1 correspondence between input and output buffers (emphasis mine):

At a simplistic level, you request (or receive) an empty input buffer, fill it up with data and send it to the codec for processing. The codec uses up the data and transforms it into one of its empty output buffers.

We have GTS tests that enforce this [1], but I suspect that the GTS environment doesn't trigger this interpolation on this device, maybe because it doesn't connect TV devices to a 60Hz screen. I'm running the tests on my Chromecast plugged into the same screen that lets me repro this issue, and so far they're all passing. Possibly because the content used by the test is not 1080p (based on https://github.com/google/ExoPlayer/issues/10445#issuecomment-1185786182).

[1] https://github.com/google/ExoPlayer/blob/ab4d37f499ba49bb3cac7938eb03ebf7133ccfe6/testutils/src/main/java/com/google/android/exoplayer2/testutil/DecoderCountersUtil.java#L51-L75

[icbaker]

I've hacked together a test using the stream provided (don't worry, I won't submit this anywhere or make it run in any automated way!) - and the same decoder counter assertions I've mentioned above. I haven't made it fail yet, it seems the number of 'rendered' output buffers matches the number of input buffers - so I need to do some more digging to understand what's going on. I wasn't seeking in my test, but I think the seek is only needed to see the bad effects of this (due to the interaction with decode-only timestamps), and I'd expect to see the duplicated frames during normal linear playback without any seeks.

[stevemayhew]

I think that a decoder is not allowed to create additional output buffers. The MediaCodec javadoc seems to make it pretty clear there's a 1:1 correspondence between input and output buffers (emphasis mine):

At a simplistic level, you request (or receive) an empty input buffer, fill it up with data and send it to the codec for processing. The codec uses up the data and transforms it into one of its empty output buffers.

We have GTS tests that enforce this [1], but I suspect that the GTS environment doesn't trigger this interpolation on this device, maybe because it doesn't connect TV devices to a 60Hz screen. I'm running the tests on my Chromecast plugged into the same screen that lets me repro this issue, and so far they're all passing. Possibly because the content used by the test is not 1080p (based on #10445 (comment)).

I can check with the content owner if you can use the MPEG-TS, seems less the an few seconds of it is all that is needed.

Only the 1080p30 highest variant that triggers the frame rate doubling. Not all encodings do, which is probably why the GTS tests pass. We have 1080p30 content that is similar but does not trigger the auto-FRC (a NASA channel variant that is 30 FPS). One thing I noticed is the has_b_frames is much higher on the content I shared with you that causes the issue. This cause the file order B frames to be very early in the stream, because of the decode order.

Still waiting for an answer from AmLogic on this https://github.com/google/ExoPlayer/pull/10468#issuecomment-1203026060

Thanks for the help @icbaker !

[icbaker]

I've managed to reproduce in a test now (it seems important to wait ~5s before seeking, I was doing just 1s and it wasn't reproing - not really sure why).

I've filed [internal b/241255564] to ask the Chromecast team to look into this from their side.

[stevemayhew]

@icbaker I promised to keep you in the loop, our reseller worked with SEI/AMLogic to get a version of their firmware that "fixes the issue". There is no change required to codec settings, it simply stops frame doubling the NTSC (drop 30 FPS) content. In my testing its only drop 30 at 1080p (1080@29.97).

Here's the feedback from our vender as well as my explanation back to them as to what is happening to / expected from MediaCodec API:

From SEI/AMLogic:

SEI / AMLogic determined that the issue was specifically happening on during tuning when the 1080 P bitrate profile was invoked on tune, so AMLogic was able to turn off the "forced I-Frame" function in this case.

My reply:

This firmware change causes the decoder to stop frame doubling, which fixes this issue:

08-08 10:20:26.098 22572 22598 D MediaCodecVideoRenderer: renderOutputBufferV21() - PTS (us): 6150400 releaseTime (us): 234062092150 pts delta: 33367 release adj (us): 26461
08-08 10:20:26.128 22572 22598 D MediaCodecVideoRenderer: renderOutputBufferV21() - PTS (us): 6183766 releaseTime (us): 234062125517 pts delta: 33366 release adj (us): 26477

I'm not sure what "during tuning" is, but anytime the player forces a position change (seek, tune, new stream startup, etc) the player:

1. flushes the codec (calls MediaCodec.flush())
2. seeks in the HLS playlist, so it loads the segment nearest the new position
3. Load the segment and passes the initial IDR to the codec (calls MediaCodec.queueInputBuffer())
4. Displays this decoded IDR unconditionally as "first frame render"
5. Passes the remaining frames from this IDR to the new target position to MediaCodec to decode only
6. Discards the frames until the decoder returns the frame matching the new target position.

The frame doubling is what prevents the player from identifying the decode only frames (as it cannot match input PTS to output timestamp.

So, for Google I would recommend you work with you OEM for the Chromecast to get this patch.

From our side, you can close this bug. Thanks! hope this is helpful for your team.

[stevemayhew]

Also, so it's clear, the pull request https://github.com/google/ExoPlayer/pull/10468 is not needed to fix the problem, only updated firmware from SEI/AMLogic.

[grp0916]

------------------ 原始邮件 ------------------ 发件人: "google/ExoPlayer" @.>; 发送时间: 2022年8月13日(星期六) 凌晨4:46 @.>; @.***>; 主题: Re: [google/ExoPlayer] Burst of invalid frame renders on seek with Android 10 AmLogic (Issue #10445)

Also, so it's clear, the pull request #10468 is not needed to fix the problem, only updated firmware from SEI/AMLogic.

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you are subscribed to this thread.Message ID: @.***>

[icbaker]

Thanks for closing the loop with the extra info @stevemayhew, I've passed it along (or back?) to Amlogic. I'll close this issue since the Chromecast-specific issue is tracked by the internal bug I've filed.