Player stopping unexpectedly

[JJSarrasin]

Version

Media3 1.5.0

More version details

No response

Devices that reproduce the issue

Vantiva Sapphire/Quartz

Devices that do not reproduce the issue

No response

Reproducible in the demo app?

No

Reproduction steps

We’re trying to update our media3 player to the latest version (1.5.0), but we’re encountering an issue. I’m not sure if you’re already aware of it.

It’s quite difficult to reproduce consistently, but our testers are providing significant feedback about the problem.

The issue occurs when the player freezes on a frame and stops playing. It looks like a pause, but the pause action isn’t triggered. Using Wireshark, we can see that the stream continues to download. There’s no audio. If we manually trigger the play/pause action, it pauses as expected, and when we trigger it again, playback resumes as if nothing happened.

This seems to occur with the following streams:

• AAC audio tracks
• Live streams (we use a 5000ms target offset)
• Tunneling enabled

I understand this ticket lacks precise details. What steps could we take to provide you with better feedback?

This problem never occurs on the previous version 1.4.0.

I couldn't reproduce in the demo app yet but maybe I didn't test it long enough.

Expected result

Continuous live playing

Actual result

The player is stopping unexpectedly

Media

If needed we can provide you a test live stream.

Bug Report

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

[marcbaechinger]

Thanks for your report!

These are the things you can do to make this actionable for us in case you are able to repro on a device:

• Best is if you can repro in the demo app an a device and provide us with the media so we can repro and look into this ourself

Else in case you can repro consistently on the device with your app:

• provide us with a sample URI to the content that repros for you if that's possible
• add an EventLogger with ExoPlayer.addAnalyticsListener(new EventLogger)
• take a bug report after you've experienced the problem
• upload/post the bug report and sample URI here or send it to [email protected] with a subject "Issue # 1962" and let us know here you've done this.

[JJSarrasin]

Hi,

We sent you some reports by mail yesterday and this morning.

We also noticed that every occurrence of the issue is accompanied by the following lines. Sometimes, we can reproduce the problem three times in ten minutes, while other times, it works flawlessly for the entire day.

12-11 16:28:32.551 519 1304 D AudioFlinger: mixer(0xf2417ea0) throttle end: throttle time(3)
12-11 16:29:29.838 519 1304 I AudioFlinger: BUFFER TIMEOUT: remove(136) from active list on thread 0xf2417ea0
12-11 16:29:29.849 519 625 W AudioFlinger: moveEffectChain_l() effect chain for session 0 not on source thread 0xf2417ea0

[JJSarrasin]

Fyi, since our rollback to 1.4.1 for our beta users, we didn't notice this issue anymore.

Is there something in 1.5.1 that could help for this issue ?

[marcbaechinger]

Thanks for your report, stream URI and the bugreport sent over email.

I can't really say much more than this needs more investigateion I'm afraid. I couldn't repro on mobile which is probably expected.

Around the timestamp 09:35:45 that you identified, playback position stopped advancing. The timeline is further refreshed and the media position instead starts to move backwards in the window. After the media position was at 6.70, ExoPlayer reports to stop loading media EventLogger: loading [eventTime=2455.29, mediaPos=6.70, window=0, period=0, false] which corresponds to a 50 second max buffer configuration in the window that was just reported to be 57.97 seconds long.

This confirms the behavior you are seeing looks like being paused and timeline and media keeps loading as expected.

Around that time there is some low memory reported for your app, but I'm unsure how that would be related without seeing ExoPlayer reporting any errors. I think there would be an error either when there is an actual OOM, or when the Allocator can't deliver for some reasons. Also you are saying after pause/play it works again.

This lets me guess of the Surface being in trouble also because there lots of such errors two minutes before:

12-11 09:33:52.446 10035 22165 10197 E BufferQueueProducer: [SurfaceTexture-0-22165-33](id:569500000042,api:3,p:22165,c:22165) detachBuffer: slot 63 is not owned by the producer (state = FREE)

where it seems a second ExoPlayer instance is started briefly after the channel was switched the last time (during the failing stream).

12-11 09:33:49.984 10035 22165 22165 I ExoPlayerImpl: Init fa28f53 [AndroidXMedia3/1.5.0] []
ExoPlayerImpl
12-11 09:33:52.465 10035 22165 22165 I ExoPlayerImpl: Release fa28f53 [AndroidXMedia3/1.5.0] [
]

According to the logs there are two Surfaces involved and I see both disconnected at '09:33:52.452'.

12-11 09:33:52.408 10035 22165 10197 D SurfaceUtils: connecting to surface 0xea42a828, reason connectToSurface(reconnect)
12-11 09:33:52.452 10035 22165 10197 D SurfaceUtils: disconnecting from surface 0xea41f7d8, reason disconnectFromSurface
12-11 C6 10035 22165 10197 D SurfaceUtils: disconnecting from surface 0xea42a828, reason disconnectFromSurface

If you can repro this again, can you check whether these Surface problems are involved again? Similar for the OOM or send the bug report to the same email address again for us.

The timing of the Surface problem doesn't match with the timestamp when it starts to pause. What I'm trying to say is that I don't know how that actually would be related.

Is there something in 1.5.1 that could help for this issue ?

I think there isn't something that is supposed to address something you are reporting.
https://github.com/androidx/media/releases/tag/1.5.1

From the logs and manifest I see this is a single-period live DASH stream. There is #1698 but there it's about a transition in multi-period and there isn't a fix release yet I think.

We need to investigate this some further.

[JJSarrasin]

Hello,

Back from vacation !

The second stream you see starting in the logs is probably a navigation in the menu with an autoplay-card triggered.

Just to let you know, it's our top priority, we've dig into the tickets you mentioned.

We will test the following versions on multiple TVs:

• 1.5.0
• 1.5.1
• 1.6.0-alpha01
• development branch (with this fix from yesterday: Stream/App freeze in DASH Multi-Period Live-Stream #1698 (comment))

And I come back to you with the results in some days, maybe it's already fix.

One thing is certain, it was working fine in 1.4.1 and the problem appear with 1.5.0.

[JJSarrasin]

After one week, I can confirm I reproducing the issue on 1.5.0 and 1.5.1. The testing is very long to reproduce, but when it occurs, it will occur very frequently on all our AAC channels.
We start our test with 1.6.0-alpha01.
By the way, even if it is a "player robustness problem" because it was working on previous version of Exoplayer, are you aware of dash stream tester to check if our streams are somewhere incorrect and causing the issue ? You would probably have more feedbacks if it was a general player issue.

[JJSarrasin]

After weeks of testing and many hours of effort, we have found a straightforward way to reproduce the issue by repeatedly unplugging and plugging the HDMI cable on our box.

Here is what I can confirm:

• The issue does not occur in version 1.4.1.
• The issue appears starting from version 1.5.0 and persists in subsequent versions up to the current release.
• The problem seems to be related to the specific commit titled "Fix truncation error accumulation on Sonic's time-stretching algorithm" from October 7, 2024.
• Specifically, the issue arises in the changes made to Sonic.java. Restoring the following assignment for expectedOutputFrames resolves the issue:

int expectedOutputFrames = outputFrameCount + (int) ((remainingFrameCount / s + pitchFrameCount) / r + 0.5f);

Could you provide more details about this regression? Is it something specific to our device or stream that is causing this behavior, or does it stem from the patch itself?

[ivanbuper]

Hi,

From your description, it seems like you've run into an underflow in Sonic, which stalls the DefaultAudioSink, and then the player. This is an issue we've fixed in 7ecaebe, available now on main, and should be available on the next 1.6.0 release. Have you tried reproducing the issue with that fix included?

For context, this is an underflow in Sonic#queueEndOfStream(). We calculate the expectedOutputFrames you mentioned above:

int expectedOutputFrames =
        outputFrameCount
            + (int)
                ((adjustedRemainingFrames / s
                            + remainingInputToCopyFrameCount
                            + accumulatedSpeedAdjustmentError
                            + pitchFrameCount)
                        / r
                    + 0.5);

expectedOutputFrames sometimes sets the value of pending output frames:

// Throw away any extra frames we generated due to the silence we added.
    if (outputFrameCount > expectedOutputFrames) {
      outputFrameCount = expectedOutputFrames;
    }

And then SonicAudioProcessor reads the outputFrameCount value:

  @Override
  public final boolean isEnded() {
    return inputEnded && (sonic == null || sonic.getOutputSize() == 0);
  }

If sonic.getOutputSize() < 0, then we've stalled the DefaultAudioSink, which would have queued EoS but would wait infinitely for processing to be completed.

One of the easiest ways I found to repro the issue was to spam playback speed changes to the player (Player#setPlaybackSpeed()), within the [0.5; 1) range, which is the problematic one. I'm assuming plugging and unplugging HDMI also works because you are forcing EoS to be queued, and you are making the number of available input and output frames quite small.

The analysis in your previous comment including the culprit CL was spot on so, kudos on that! Please let me know if 7ecaebe fixes the issue, otherwise we might be dealing with something different. Thanks!

[JJSarrasin]

Hello,

Thanks for the quick feedback. The nightly build seems to work fine, so I guess it is the fix you mentioned.

We will stick to the 1.5.1 with the line change until there is a beta/rc/final 1.6.0 release.