STATE_ENDED not sent for very short files, worked in version 1.0.2 and older #538

faltiska · 2023-07-21T11:28:13Z

Version

Media3 1.1.0

More version details

I use an ExoPlayer to play audio files of various lengths, some of them very short.
After updating to 1.1.0 I found that the STATE_ENDED event is no longer generated for the very short clips.
It still works fine for longer audio clips.

Events STATE_BUFFERING and STATE_READY are still generated, only ENDED is missing.

Devices that reproduce the issue

Any device.

Devices that do not reproduce the issue

No response

Reproducible in the demo app?

No

Reproduction steps

    AudioAttributes attributes = new AudioAttributes.Builder().setContentType(AUDIO_CONTENT_TYPE_MUSIC).build();

    ExoPlayer player = new ExoPlayer.Builder(App.context)
            .setAudioAttributes(attributes, false)
            .build();
    player.setAudioSessionId(audioSessionId);
    player.setWakeMode(WAKE_MODE_NETWORK);
    player.setVolume(1f);
    player.setPlayWhenReady(true);


    player.addListener(new Player.Listener() {
        public void onPlaybackStateChanged(int state) {
            //print states or put a breakpoint here
        }
        @Override
        public void onPlayerError(@NonNull PlaybackException error) {
            //print error or put a breakpoint here
        }
    });
    player.setMediaItem(mediaItem); //use the clip I attached to the bug report
    player.prepare();

Expected result

The STATE_ENDED event should be generated.

Actual result

STATE_ENDED result never comes.

Media

very_short_audio.zip

Bug Report

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

The text was updated successfully, but these errors were encountered:

icbaker · 2023-07-21T14:29:02Z

Thanks for the report. I can reproduce the problem in the demo app with no changes (just playing the provided sample).

At 1.0.2:

Unable to match the desired swap behavior.
surfaceSize [eventTime=49.78, mediaPos=0.19, window=0, period=0, 0, 0]
Release 816c631 [AndroidXMedia3/1.0.2] [redfin, Pixel 5, Google, 33] [media3.common, media3.database, media3.datasource.cronet, media3.datasource, media3.ui, media3.exoplayer, media3.decoder, media3.extractor]
audioDisabled [eventTime=49.81, mediaPos=0.19, window=0, period=0]
Init c963c91 [AndroidXMedia3/1.0.2] [redfin, Pixel 5, Google, 33]
playWhenReady [eventTime=0.00, mediaPos=0.00, window=0, true, USER_REQUEST]
surfaceSize [eventTime=0.00, mediaPos=0.00, window=0, 0, 0]
timeline [eventTime=0.00, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=PLAYLIST_CHANGED
  period [?]
  window [?, seekable=false, dynamic=true]
]
mediaItem [eventTime=0.00, mediaPos=0.00, window=0, reason=PLAYLIST_CHANGED]
state [eventTime=0.00, mediaPos=0.00, window=0, BUFFERING]
Unable to match the desired swap behavior.
surfaceSize [eventTime=0.03, mediaPos=0.00, window=0, 1080, 2138]
Failed to find sync for id=0
stop(78): called with 3039 frames delivered
Expecting binder but got null!
loading [eventTime=0.04, mediaPos=0.00, window=0, period=0, true]
timeline [eventTime=0.04, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE
  period [?]
  window [?, seekable=false, dynamic=false]
]
timeline [eventTime=0.04, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE
  period [0.19]
  window [0.19, seekable=true, dynamic=false]
]
audioEnabled [eventTime=0.04, mediaPos=0.00, window=0, period=0]
tracks [eventTime=0.04, mediaPos=0.00, window=0, period=0
  group [
    [X] Track:0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000, supported=YES
  ]
]
loading [eventTime=0.04, mediaPos=0.00, window=0, period=0, false]
downstreamFormat [eventTime=0.04, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000]
audioInputFormat [eventTime=0.05, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000]
state [eventTime=0.05, mediaPos=0.01, window=0, period=0, READY]
isPlaying [eventTime=0.05, mediaPos=0.01, window=0, period=0, true]
state [eventTime=0.23, mediaPos=0.19, window=0, period=0, ENDED]
isPlaying [eventTime=0.23, mediaPos=0.19, window=0, period=0, false]

At 1.1.0 (missing the state [eventTime=0.23, mediaPos=0.19, window=0, period=0, ENDED] and isPlaying [eventTime=0.23, mediaPos=0.19, window=0, period=0, false] lines at the bottom):

Init 1648e56 [AndroidXMedia3/1.1.0] [redfin, Pixel 5, Google, 33]
Accessing hidden method Landroid/media/AudioTrack;->getLatency()I (unsupported, reflection, allowed)
playWhenReady [eventTime=0.00, mediaPos=0.00, window=0, true, USER_REQUEST]
surfaceSize [eventTime=0.00, mediaPos=0.00, window=0, 0, 0]
timeline [eventTime=0.01, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=PLAYLIST_CHANGED
  period [?]
  window [?, seekable=false, dynamic=true]
]
mediaItem [eventTime=0.01, mediaPos=0.00, window=0, reason=PLAYLIST_CHANGED]
state [eventTime=0.01, mediaPos=0.00, window=0, BUFFERING]
Unable to match the desired swap behavior.
surfaceSize [eventTime=0.04, mediaPos=0.00, window=0, 1080, 2138]
Failed to find sync for id=0
Expecting binder but got null!
loading [eventTime=0.05, mediaPos=0.00, window=0, period=0, true]
timeline [eventTime=0.05, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE
  period [?]
  window [?, seekable=false, dynamic=false]
]
timeline [eventTime=0.05, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE
  period [0.19]
  window [0.19, seekable=true, dynamic=false]
]
audioEnabled [eventTime=0.05, mediaPos=0.00, window=0, period=0]
tracks [eventTime=0.05, mediaPos=0.00, window=0, period=0
  group [
    [X] Track:0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000, supported=YES
  ]
]
downstreamFormat [eventTime=0.06, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000]
audioInputFormat [eventTime=0.06, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=256000, channels=1, sample_rate=16000]
loading [eventTime=0.07, mediaPos=0.00, window=0, period=0, false]
state [eventTime=0.07, mediaPos=0.00, window=0, period=0, READY]
isPlaying [eventTime=0.07, mediaPos=0.00, window=0, period=0, true]
stop(79): called with 3039 frames delivered

icbaker · 2023-07-21T15:24:59Z

It seems to be fixed by reverting 62c0352 on top of 1.1.0.

icbaker · 2023-07-21T15:44:48Z

I added some logging in AudioTrackPositionTracker.hasPendingData to dig into the difference between the calculations before and after 62c0352:

long currentPositionUs = getCurrentPositionUs(/* sourceEnded= */ false);
long currentPositionInFrames = durationUsToFrames(currentPositionUs);

ATPT.hasPendingData(): writtenFrames=3039, getPlaybackHeadPosition()=3039, currentPositionUs=189937, outputSampleRate=16000, currentPositionInFrames=3038

The maths calculating currentPositionInFrames in AudioTrackPositionTracker.durationUsToFrames is:

(189937 * 16000) / 1000000 = 3038.992

Which is getting rounded down to 3038 by the integer maths.

I have a provisional change to use Util.ceilDivide in AudioTrackPositionTracker.durationUsToFrames, which fixes the problem, but I'm not sure if it's generally correct. I will send it to @tonihei internally to discuss.

andrwq · 2023-07-30T22:03:51Z

STATE_ENDED is also never sent when seeking till (or close to) the end of a timeline period. Using Util.ceilDivide() fixes the problem in that case as well.

shenguojun · 2023-08-10T11:08:53Z

I have encountered the same issue and hope it can be fixed as soon as possible.

This fixes a bug with playing very short audio files, introduced by fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). #minor-release Issue: androidx/media#538 PiperOrigin-RevId: 554481782

This fixes a bug with playing very short audio files, introduced by fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). #minor-release Issue: #538 PiperOrigin-RevId: 554481782

This fixes a bug with playing very short audio files, introduced by fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). Issue: androidx/media#538 PiperOrigin-RevId: 554481782 (cherry picked from commit a9a2451)

This fixes a bug with playing very short audio files, introduced by fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). Issue: #538 PiperOrigin-RevId: 554481782 (cherry picked from commit 6e91f0d)

This fixes a bug with playing very short audio files, introduced by fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). Issue: androidx/media#538 PiperOrigin-RevId: 554481782 (cherry picked from commit a9a2451)

This fixes a bug with playing very short audio files, introduced by androidx@fe71087 The existing code using floor integer division results in playback never transitioning to `STATE_ENDED` because at the end of playback for the short sample clip provided `currentPositionUs=189937`, `outputSampleRate=16000` and `(189937 * 16000) / 1000000 = 3038.992`, while `writtenFrames=3039`. This is fixed by using `Util.ceilDivide` so we return `3039`, which means `AudioTrackPositionTracker.hasPendingData()` returns `false` (since `writtenFrames == durationUsToFrames(getCurrentPositionUs(/* sourceEnded= */ false))`). #minor-release Issue: androidx#538 PiperOrigin-RevId: 554481782

faltiska added bug needs triage labels Jul 21, 2023

icbaker self-assigned this Jul 21, 2023

icbaker removed the needs triage label Jul 21, 2023

icbaker closed this as completed Aug 16, 2023

icbaker mentioned this issue Aug 24, 2023

Playing really small files with the latest build (2.19.1) still fails to detect the file completion google/ExoPlayer#11267

Closed

TheMelody mentioned this issue Aug 30, 2023

STATE_ENDED not sent for very short files #622

Closed

androidx locked and limited conversation to collaborators Oct 16, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

STATE_ENDED not sent for very short files, worked in version 1.0.2 and older #538

STATE_ENDED not sent for very short files, worked in version 1.0.2 and older #538

faltiska commented Jul 21, 2023

icbaker commented Jul 21, 2023

icbaker commented Jul 21, 2023

icbaker commented Jul 21, 2023

andrwq commented Jul 30, 2023

shenguojun commented Aug 10, 2023

STATE_ENDED not sent for very short files, worked in version 1.0.2 and older #538

STATE_ENDED not sent for very short files, worked in version 1.0.2 and older #538

Comments

faltiska commented Jul 21, 2023

Version

More version details

Devices that reproduce the issue

Devices that do not reproduce the issue

Reproducible in the demo app?

Reproduction steps

Expected result

Actual result

Media

Bug Report

icbaker commented Jul 21, 2023

icbaker commented Jul 21, 2023

icbaker commented Jul 21, 2023

andrwq commented Jul 30, 2023

shenguojun commented Aug 10, 2023