Playback starts from a negative position with multi-period DASH

[zilinx]

ExoPlayer Version

2.18.1

Devices that reproduce the issue

Probably any device. I used Samsung Galaxy S10 (Android 12) and Google TV HD (Android 11) for development.

Devices that do not reproduce the issue

No response

Reproducible in the demo app?

Yes

Reproduction steps

I haven't tested all versions in between, but the issue could not be reproduced on version 2.14.1.

Reproduced using a multi-period DASH (example sent by e-mail).
When checking player.getCurrentPosition() after the player has prepared, the first value is -21.

It seems more than coincidental that the negative offset is -21ms as this represents a (floored) duration of a single frame of audio (21.667mS - hence why a pair of priming frames make 43ms, which is the difference between expected and actual segment duration for the first segment).

Expected result

Playback starts at 0

Actual result

Playback starts at -21 (when using onPlaybackStateChanged to read currentPosition, sometimes this is not visible, but should happen often enough).

Media

I will send a sample by email. The samples are tagged for issue 10940

Bug Report

• You will email the zip file produced by adb bugreport to [email protected] after filing this issue.

[marcbaechinger]

Hmm, I can not repro this. The DASH URI that was part of the patch you sent by email (thank you), still worked and when I play this I can't see any anomalies.

The DashTimeline that is created looks fine and when I call player.getCurrentPosition() when I receive the READY state in the demo app I get 0 as expected. That correspond to the first period of the timeline having a duration of 12000 millis and a positionInWindowUs of 0.

Can you confirm you are seeing this problem when playing with a normal DashMediaSource instead of the DAI integration being in place?

[zilinx]

Thank you for looking into the issue! Yes, I can reproduce it every time, though in some cases at the time of READY the value will still be 0 (but then change to -21 afterwards).
I even tried replacing PlayerActivity's DefaultMedisSourceFactory to use DashMediaSource.Factory directly instead, but it still starts at -21.

I tried to pinpoint who is changing the value to -21 (or -21333 us to be exact). I got as far as DefaultMediaClock, which jumped from 1000000000000 to 999999978667. It's using rendererClock, not the standalone. I hope this information helps!

11:47:38.460 23486-23486 [ExoPlayerImpl] getCurrentPosition: 0
11:47:38.461 23486-23677 [DefaultMediaClock] syncAndGetPositionUs: 1000000000000, using standalone: false
11:47:38.461 23486-23677 [ExoPlayerImplInternal] updatePlaybackPositions: 0, renderer pos: 1000000000000
11:47:38.490 23486-23486 [ExoPlayerImpl] getCurrentPosition: 0
11:47:38.490 23486-23486 [ExoPlayerImpl] getCurrentPosition: 0
11:47:38.499 23486-23677 [DefaultMediaClock] syncAndGetPositionUs: 999999978667, using standalone: false
11:47:38.499 23486-23677 [ExoPlayerImplInternal] updatePlaybackPositions: -21333, renderer pos: 999999978667
11:47:38.504 23486-23486 [ExoPlayerImpl] getCurrentPosition: -21333

To double-check that this is unlikely to be specific to the device, I tested on Xiaomi MiBox 4 (Android 9) and the issue could be reproduced there, too.

Edit: I checked which renderer it's using to clock and it's com.google.android.exoplayer2.audio.MediaCodecAudioRenderer (as suspected).
Edit2: I ran the sample on the emulator (Android 11) and I could reproduce it there, too. Though it seemed to update much later (always after READY). Presumably because the emulator is more interested in melting my CPU than in rendering things, hehe.

[zilinx]

I narrowed down the version on which the issue started occurring - it's 2.16.0.
On 2.15.1 I couldn't reproduce this problem.

[marcbaechinger]

Yep, I see this as well when MediaCodecAudioRenderer is used as the clock. Thanks for clarification:

2023-01-26 18:19:21.232 13519-13698 clock                   androidx.media3.demo.main            D  currentPositionUs is 1000000000000
2023-01-26 18:19:21.232 13519-13698 clock                   androidx.media3.demo.main            D  currentPositionUs updated to 999999978667

[marcbaechinger]

I see that the position is adjusted in DefaultAudioSink.applyMediaPositionParameters(). The mediaPositionParameters.mediaTimeUs has a value of 999999978667. This value comes from the the outputBufferInfo.outputBufferInfo.presentationTimeUs in MediaCodecRenderer.drainOutputBuffer.

@tonihei Can you look into this? We have introduced this with cl/291923069. I'm not sure where this start presentationTimeUs is coming from. I'd say from the media but not sure and you can probably answer more efficiently and see whether we need to fix/adjust something to always start with 0.

[tonihei]

Thanks for the detailed analysis above! The change between 2.15.1 and 2.16.0 that causes this to happen is 4e6960e. However, this isn't really the problem, it just helped to surface it.

The first fMP4 audio segment contains an edit list instructing the player to move timestamps by -43ms. So the timestamps of the first samples in the fMP4 container become: [-43, -21, 0, 21, 43, 64, ....]. ExoPlayer knows that playback should start at position 0 and advances to the last sample where the timestamp is less than the intended start time. So it just drops the first sample with -43 and then attempts to start playback at the sample with timestamp -21. It should actually also skip the sample at -21 and start with the one at 0.

So why is the commit above relevant? Some decoders are known to have unexpected behavior when fed with negative timestamps. And in this case the decoder decided to "correct" the timestamp to zero after decoding and the problem was never really visible. 4e6960e was done to avoid issues with negative timestamps in decoders, which can be achieved by adding a large offset to all times. At this point the decoder started working correctly and returned the timestamp we fed in to it. So now, we started observing the -21ms timestamp of the sample we should have skipped.