Improve stuck buffering detection to explicitly detect that no buffer is available for rendering
- Dominant language
- Java
- Stars
- 21.9k
- Forks
- 6k
- PR merge metrics
- No merged PRs in 30d
Description
When playing a specific HLS VOD stream the playback always stalls (video freezes, audio stops, CC stops) at the same time and at the same frame (around the 8 minutes from the beginning). Pausing/unpausing does not help. Seeking helps to resume playback.
I tried to debug the issue after playback stops: LoadControl reports that the media buffer is full (at 50seconds). But both Video and Audio renderers report that they are not ready in the following line:
ExoPlayerImplInternal.java:
```
boolean allowsPlayback =
isReadingAhead || isWaitingForNextStream || renderer.isReady() || renderer.isEnded();
```
VLC and ffplay play this stream without issues.
Unfortunately I cannot provide a link to the stream. But it looks like the following:
```
#EXTM3U
#EXT-X-PLAYLIST-TYPE:VOD
#EXT-X-VERSION:3
#EXT-X-START:TIME-OFFSET=0
#EXT-X-TARGETDURATION:17
#EXT-X-MEDIA-SEQUENCE:11048
#EXT-X-KEY:METHOD=AES-128,URI="[edit]"
#EXTINF:8.341667,
11048.ts
.......
#EXTINF:8.341667,
11090.ts
#EXTINF:16.683333,
11091.ts
#EXTINF:16.683333,
11092.ts
#EXTINF:8.341667,
11093.ts
```
Logcat output:
```
2021-10-10 22:21:26.503 28898-28898/com.player D/EventLogger: downstreamFormat [eventTime=6.90, mediaPos=0.00, window=0, period=0, id=0, mimeType=null, bitrate=3500000, codecs=mp4a.40.2, avc1.4d401e, res=1280x720]
2021-10-10 22:21:26.913 28898-28898/com.player D/EventLogger: videoDecoderInitialized [eventTime=7.29, mediaPos=0.00, window=0, period=0, OMX.rk.video_decoder.hevc]
2021-10-10 22:21:26.934 28898-28898/com.player D/EventLogger: videoInputFormat [eventTime=7.33, mediaPos=0.00, window=0, period=0, id=0, mimeType=video/hevc, bitrate=3500000, codecs=hvc1.1.2.L93, res=1280x720]
2021-10-10 22:21:27.006 28898-28898/com.player D/EventLogger: audioDecoderInitialized [eventTime=7.41, mediaPos=0.00, window=0, period=0, OMX.google.aac.decoder]
2021-10-10 22:21:27.032 28898-28898/com.player D/EventLogger: audioInputFormat [eventTime=7.42, mediaPos=0.00, window=0, period=0, id=1/257, mimeType=audio/mp4a-latm, codecs=mp4a.40.2, channels=2, sample_rate=48000, language=en]
2021-10-10 22:21:27.190 28898-28898/com.player D/EventLogger: tracks [eventTime=7.58, mediaPos=0.00, window=0, period=0
2021-10-10 22:21:27.191 28898-28898/com.player D/EventLogger: MediaCodecVideoRenderer [
2021-10-10 22:21:27.191 28898-28898/com.player D/EventLogger: Group:0, adaptive_supported=N/A [
2021-10-10 22:21:27.193 28898-28898/com.player D/EventLogger: [X] Track:0, id=0, mimeType=video/hevc, bitrate=3500000, codecs=hvc1.1.2.L93, res=1280x720, supported=YES
2021-10-10 22:21:27.197 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.207 28898-28898/com.player D/EventLogger: Metadata [
2021-10-10 22:21:27.207 28898-28898/com.player D/EventLogger: HlsTrackMetadataEntry
2021-10-10 22:21:27.207 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.208 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.208 28898-28898/com.player D/EventLogger: MediaCodecAudioRenderer [
2021-10-10 22:21:27.209 28898-28898/com.player D/EventLogger: Group:0, adaptive_supported=N/A [
2021-10-10 22:21:27.212 28898-28898/com.player D/EventLogger: [X] Track:0, id=1/257, mimeType=audio/mp4a-latm, codecs=mp4a.40.2, channels=2, sample_rate=48000, language=en, supported=YES
2021-10-10 22:21:27.212 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.212 28898-28898/com.player D/EventLogger: Group:1, adaptive_supported=N/A [
2021-10-10 22:21:27.213 28898-28898/com.player D/EventLogger: [ ] Track:0, id=1/258, mimeType=audio/mp4a-latm, codecs=mp4a.40.2, channels=2, sample_rate=48000, language=enm, supported=YES
2021-10-10 22:21:27.230 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.230 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.231 28898-28898/com.player D/EventLogger: FfmpegAudioRenderer []
2021-10-10 22:21:27.231 28898-28898/com.player D/EventLogger: TextRenderer [
2021-10-10 22:21:27.232 28898-28898/com.player D/EventLogger: Group:0, adaptive_supported=N/A [
2021-10-10 22:21:27.233 28898-28898/com.player D/EventLogger: [X] Track:0, id=cc1:English, mimeType=application/cea-608, language=en, supported=YES
2021-10-10 22:21:27.233 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.240 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.241 28898-28898/com.player D/EventLogger: MetadataRenderer [
2021-10-10 22:21:27.241 28898-28898/com.player D/EventLogger: Group:0, adaptive_supported=N/A [
2021-10-10 22:21:27.257 28898-28898/com.player D/EventLogger: [X] Track:0, id=null, mimeType=application/id3, supported=YES
2021-10-10 22:21:27.258 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.258 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.261 28898-28898/com.player D/EventLogger: CameraMotionRenderer []
2021-10-10 22:21:27.262 28898-28898/com.player D/EventLogger: ]
2021-10-10 22:21:27.542 28898-28898/com.player D/EventLogger: videoSize [eventTime=7.93, mediaPos=0.00, window=0, period=0, 1280, 720]
2021-10-10 22:21:27.581 28898-28898/com.player D/EventLogger: renderedFirstFrame [eventTime=7.96, mediaPos=0.00, window=0, period=0, Surface(name=null)/@0xcfe893f]
2021-10-10 22:21:28.426 28898-28898/com.player D/EventLogger: state [eventTime=8.81, mediaPos=0.02, window=0, period=0, READY]
2021-10-10 22:21:28.465 28898-28898/com.player D/EventLogger: isPlaying [eventTime=8.84, mediaPos=0.02, window=0, period=0, true]
2021-10-10 22:21:32.503 28898-28898/com.player D/EventLogger: state [eventTime=12.91, mediaPos=3.98, window=0, period=0, BUFFERING]
2021-10-10 22:21:32.507 28898-28898/com.player D/EventLogger: isPlaying [eventTime=12.91, mediaPos=3.99, window=0, period=0, false]
```
```
2021-10-10 22:33:23.596 28898-28898/com.player D/EventLogger: state [eventTime=724.00, mediaPos=437.29, window=0, period=0, BUFFERING]
2021-10-10 22:33:23.599 28898-28898/com.player D/EventLogger: isPlaying [eventTime=724.01, mediaPos=437.29, window=0, period=0, false]
2021-10-10 22:33:23.623 28898-28898/com.player E/EventLogger: audioTrackUnderrun [eventTime=724.03, mediaPos=437.29, window=0, period=0, 53664, 279, 333]
2021-10-10 22:33:30.539 28898-28898/com.player D/EventLogger: state [eventTime=730.95, mediaPos=437.29, window=0, period=0, READY]
2021-10-10 22:33:30.539 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.540 28898-28898/com.player D/EventLogger: isPlaying [eventTime=730.95, mediaPos=437.29, window=0, period=0, true]
2021-10-10 22:33:30.550 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.620 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.631 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.642 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.653 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.673 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353884148423295 < limitNs: 353890873556812 < mStartNs: 353890953556812
2021-10-10 22:33:30.684 28898-29480/com.player W/AudioTrack: getTimestamp() location moved from kernel to server
2021-10-10 22:33:32.877 28898-28898/com.player D/EventLogger: state [eventTime=733.28, mediaPos=439.53, window=0, period=0, BUFFERING]
2021-10-10 22:33:32.878 28898-28898/com.player D/EventLogger: isPlaying [eventTime=733.28, mediaPos=439.53, window=0, period=0, false]
2021-10-10 22:33:33.302 28898-28898/com.player E/EventLogger: audioTrackUnderrun [eventTime=733.71, mediaPos=439.53, window=0, period=0, 53664, 279, 723]
2021-10-10 22:33:40.374 28898-28898/com.player D/EventLogger: state [eventTime=740.78, mediaPos=439.53, window=0, period=0, READY]
2021-10-10 22:33:40.376 28898-28898/com.player D/EventLogger: isPlaying [eventTime=740.78, mediaPos=439.53, window=0, period=0, true]
2021-10-10 22:33:40.377 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353893827568101 < limitNs: 353900708589300 < mStartNs: 353900788589300
2021-10-10 22:33:40.471 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353893827568101 < limitNs: 353900708589300 < mStartNs: 353900788589300
2021-10-10 22:33:40.490 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353893827568101 < limitNs: 353900708589300 < mStartNs: 353900788589300
2021-10-10 22:33:40.501 28898-29480/com.player D/AudioTrack: correcting timestamp time for pause, currentTimeNanos: 353893827568101 < limitNs: 353900708589300 < mStartNs: 353900788589300
2021-10-10 22:33:40.512 28898-29480/com.player W/AudioTrack: getTimestamp() location moved from kernel to server
2021-10-10 22:33:41.859 28898-28898/com.player D/EventLogger: loading [eventTime=742.27, mediaPos=440.90, window=0, period=0, false]
2021-10-10 22:33:42.953 28898-28898/com.player D/EventLogger: state [eventTime=743.36, mediaPos=441.98, window=0, period=0, BUFFERING]
2021-10-10 22:33:42.955 28898-28898/com.player D/EventLogger: isPlaying [eventTime=743.36, mediaPos=441.98, window=0, period=0, false]
```
- Tested on ExoPlayer versions 2.14.1 and 2.15.1
- Android 9
Contributor guide
Assessment
This issue has not been assessed yet.