Skip to content

Playback starts from a negative position with multi-period DASH #10941

Closed
Closed
Playback starts from a negative position with multi-period DASH#10941
Assignees
tonihei
Labels
bug

Description

@zilinx
zilinx
opened on Jan 24, 2023

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.

Activity

  1. zilinx
    added
    bug
    needs triage
    on Jan 24, 2023
  2. zilinx
    changed the title [-]Playback starts from a negative position when using [/-] [+]Playback starts from a negative position with multi-period DASH[/+] on Jan 24, 2023
  3. marcbaechinger
    self-assigned this
    on Jan 25, 2023

  4. marcbaechinger commented on Jan 25, 2023

    @marcbaechinger
    marcbaechinger
    on Jan 25, 2023
    Contributor

    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?

  5. marcbaechinger
    added
    need more info
    and removed
    needs triage
    on Jan 25, 2023

  6. zilinx commented on Jan 26, 2023

    @zilinx
    zilinx
    on Jan 26, 2023
    Author

    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.

  7. google-oss-bot
    added
    needs triage
    and removed
    need more info
    on Jan 26, 2023

  8. zilinx commented on Jan 26, 2023

    @zilinx
    zilinx
    on Jan 26, 2023
    Author

    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.

  9. marcbaechinger commented on Jan 26, 2023

    @marcbaechinger
    marcbaechinger
    on Jan 26, 2023
    Contributor

    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
  10. marcbaechinger
    removed
    needs triage
    on Jan 26, 2023

  11. marcbaechinger commented on Jan 26, 2023

    @marcbaechinger
    marcbaechinger
    on Jan 26, 2023
    Contributor

    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.

  12. marcbaechinger
    assigned
    tonihei
    and unassigned
    marcbaechinger
    on Jan 26, 2023
  13. marcbaechinger
    added
    needs triage
    on Jan 26, 2023

  14. tonihei commented on Jan 27, 2023

    @tonihei
    tonihei
    on Jan 27, 2023
    Collaborator

    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.

  15. tonihei
    removed
    needs triage
    on Jan 27, 2023
  16. christosts
    added a commit that references this issue on Feb 1, 2023

    Fix timestamp comparison for seeks in fMP4

    ac3017b
  17. christosts
    added a commit that references this issue on Feb 15, 2023

    Fix timestamp comparison for seeks in fMP4

    284bf97
  18. harishdm
    added a commit that references this issue on Feb 15, 2023

    Fix timestamp comparison for seeks in fMP4

    00436a0
  19. christosts
    added a commit that references this issue on Feb 16, 2023

    Fix timestamp comparison for seeks in fMP4

    631ff80
  20. tonihei
    closed this as completedon Apr 4, 2023
  21. google
    locked and limited conversation to collaborators on Jun 4, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

bug

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions