Skip to content

Target duration stall when loading a live media playlist with one segment #7556

@xtne6f

Description

@xtne6f

What version of Hls.js are you using?

v1.6.13

What browser (including version) are you using?

Edge v140.0.3485.81

What OS (including version) are you using?

Windows 11

Test stream

No response

Configuration

{
  "debug": true
}

Additional player setup steps

Create a simple live streaming playlist.
To make it easier to reproduce the problem, it is recommended to set the segment interval to a longer value (6 seconds or so).
I created "main.m3u8" using the following ffmpeg(v8.0) command. Save as streaming.sh:

#!/bin/sh
rm main.m3u8
ffmpeg -f lavfi -i testsrc2=512x288:rate=25 -re \
  -f lavfi -i sine -c:v libx264 -flags +cgop -g 150 -keyint_min 150 \
  -c:a aac -hls_playlist_type event -segment_list_flags +live main.m3u8

Then, place the following demo.html on any HTTP server:

<!DOCTYPE html><meta charset=utf-8><title></title>
<script src="hls.js"></script>
<video id="video" controls></video>
<input type="button" value="PLAY" onclick="play()">
<script>
function play() {
  var video = document.getElementById('video');
  var hls = new Hls({debug: true});
  hls.loadSource('main.m3u8');
  hls.attachMedia(video);
  video.play();
}
</script>

Checklist

Steps to reproduce

  1. Access the demo.html page in any browser.
  2. Run streaming.sh.
  3. The first "main.m3u8" will be created by ffmpeg after 6 seconds, so please wait for at least 6 seconds.
  4. Click "PLAY" button on the page.

Expected behaviour

After step 3, the content of "main.m3u8" is as follows:

#EXTM3U
#EXT-X-VERSION:3
#EXT-X-TARGETDURATION:6
#EXT-X-MEDIA-SEQUENCE:0
#EXT-X-PLAYLIST-TYPE:EVENT
#EXTINF:6.000000,
main0.ts

According to the annotation #EXTINF:6.000000,, hls.js is expected to access "main.m3u8" again around 6 seconds after step 4.
Prior to "v1.6.0-beta.2", or more precisely prior to commit 88be787, it works as expected.

What actually happened?

hls.js accesses "main.m3u8" again around 6+6=12 seconds after step 4, so the player stalls for about 6 seconds.
This seems to be because handleTrackOrLevelPlaylist() (playlist-loader.ts) and playlistLoaded() (base-playlist-controller.ts) add the result of computeReloadInterval() to details.requestScheduled twice.

This issue may be related to PR #7453.

Console output

logger.ts:102 [log] > Debug logs enabled for "Hls instance" in hls.js version 1.6.13
hls.ts:579 [log] > stopLoad
hls.ts:513 [log] > loadSource:http://***/main.m3u8
interstitials-controller.ts:288 [log] > [interstitials]: clear schedule state
stream-controller.ts:601 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:466 [log] > attachMedia
buffer-controller.ts:320 [log] > [buffer-controller]: created media source: MediaSource
level-controller.ts:351 [log] > [level-controller]: manifest loaded, 1 level(s) found, first bitrate: 0
buffer-controller.ts:266 [log] > [buffer-controller]: 1 bufferCodec event(s) expected.
playlist-loader.ts:397 [log] > auto startLoad with configured startPosition -1
hls.ts:556 [log] > startLoad(-1)
level-controller.ts:450 [log] > [level-controller]: Switching to level 0 (SDR @0) from level -1
base-playlist-controller.ts:346 [log] > [level-controller]: reload live playlist 0bps in 5960 ms
base-stream-controller.ts:2230 [log] > [stream-controller]: STOPPED->IDLE
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: STOPPED->IDLE
base-playlist-controller.ts:216 [log] > [level-controller]: live playlist 0 REFRESHED 0--1
base-playlist-controller.ts:346 [log] > [level-controller]: reload live playlist 0bps in 11957 ms
stream-controller.ts:661 [log] > [stream-controller]: Level 0 loaded [0,0], cc [0, 0] duration:6
base-stream-controller.ts:1763 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: 0->0 fragments: 1
base-stream-controller.ts:1818 [log] > [stream-controller]: Setting startPosition to -1 to start at live edge 0
interstitials-controller.ts:1036 [log] > [interstitials]: [checkStart] Advancing timeline position to -1
buffer-controller.ts:1546 [log] > [buffer-controller]: Media source opened
buffer-controller.ts:1352 [log] > [buffer-controller]: Updating MediaSource duration to 6.000
interstitials-controller.ts:1036 [log] > [interstitials]: [checkStart] Advancing timeline position to -1
buffer-controller.ts:1375 [log] > [buffer-controller]: checkPendingTracks (pending: 0 codec events expected: 1) {}
base-stream-controller.ts:1377 [log] > [stream-controller]: Setting startPosition to 0 to match start frag at live edge. mainStart: -1 liveSyncPosition: 0 frag.start: 0
base-stream-controller.ts:965 [log] > [stream-controller]: Loading main sn: 0 of level 0 (frag:[0.000-6.000]) cc: 0 [0-0], target: 0
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:88 [log] > injecting Web Worker for "main"
transmuxer-interface.ts:238 [log] > [transmuxer-interface]: Starting new transmux session for main sn: 0 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:537 [log] > [stream-controller]: Loaded main sn: 0 of level 0
d37530bb-3833-4e51-a597-01e41088e452:1168 [log] > Debug logs enabled for "main" in hls.js version 1.6.13
transmuxer-interface.ts:396 [log] > [mp4-remuxer]: ISGenerated flag reset
transmuxer-interface.ts:396 [log] > [mp4-remuxer]: Reset initPTS: null > null
transmuxer-interface.ts:396 [log] > [mp4-remuxer]: reset next timestamp
d37530bb-3833-4e51-a597-01e41088e452:11133 [log] > manifest codec:undefined, parsed codec:mp4a.40.2, channels:1, rate:44100 (ADTS object type:2 sampling index:4)
transmuxer-interface.ts:396 [log] > [mp4-remuxer]: Found initPTS at playlist time: 0 offset: 1.4567777777777777 (131110/90000) trackId: 1
base-stream-controller.ts:2230 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1490 [log] > [stream-controller]: Init audio buffer, container:audio/mp4, codecs[selected/level/parsed]=[mp4a.40.2//mp4a.40.2]
stream-controller.ts:1519 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[/avc1.640015]
buffer-controller.ts:594 [log] > [buffer-controller]: BUFFER_CODECS: "audio,video" (current SB count 0)
buffer-controller.ts:1375 [log] > [buffer-controller]: checkPendingTracks (pending: 2 codec events expected: 1) {"audio":{"listeners":[],"codec":"mp4a.40.2","container":"audio/mp4","levelCodec":"mp4a.40.2","metadata":{"channelCount":1},"id":"main"},"video":{"listeners":[],"codec":"avc1.640015","container":"video/mp4","metadata":{"width":512,"height":288},"id":"main"}}
buffer-controller.ts:1444 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2) {"listeners":[],"codec":"mp4a.40.2","container":"audio/mp4","levelCodec":"mp4a.40.2","metadata":{"channelCount":1},"id":"main"}
buffer-controller.ts:1444 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.640015) {"listeners":[],"codec":"avc1.640015","container":"video/mp4","metadata":{"width":512,"height":288},"id":"main"}
buffer-controller.ts:1413 [log] > [buffer-controller]: SourceBuffers created. Running queue: 
video: (SourceBuffer) 
audio: (SourceBuffer) 
audiovideo: (none) }
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: 0 of level 0 cc: 0
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: 0 of level 0 cc: 0
audio-stream-controller.ts:153 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 1.4567777777777777 (131110/90000) trackId: 1
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: 0 of level 0 cc: 0
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: 0 of level 0 cc: 0
transmuxer-interface.ts:396 [log] > [transmuxer.ts]: Flushed main sn: 0 of level 0
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:2177 [log] > [stream-controller]: Parsed main sn: 0 of level 0 (frag:[0.000-6.023])
buffer-controller.ts:1639 [log] > [buffer-controller]: Updating audio SourceBuffer timestampOffset to -1.4567777777777777 (sn: 0 cc: 0)
buffer-controller.ts:1639 [log] > [buffer-controller]: Updating video SourceBuffer timestampOffset to -1.4567777777777777 (sn: 0 cc: 0)
base-stream-controller.ts:768 [log] > [stream-controller]: Buffered main sn: 0 of level 0 (frag:[0.000-6.023] > buffer:[0.023-5.944])
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSED->IDLE
gap-controller.ts:602  [warn] > [gap-controller]: skipping hole, adjusting currentTime from 0 to 0.1
_trySkipBufferHole @ gap-controller.ts:602
poll @ gap-controller.ts:274
tick @ gap-controller.ts:147
setInterval
setInterval @ task-loop.ts:71
onMediaAttached @ gap-controller.ts:84
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
BufferController._this2._onMediaSourceOpen @ buffer-controller.ts:1555
[NEW] Explain Console errors by using Copilot in Edge: click
         
         to explain an error. 
        Learn more
        Don't show again
interstitials-controller.ts:2005 [log] > [interstitials]: INTERSTITIALS_BUFFERED_TO_BOUNDARY [primary: 0.00-Infinity]
base-stream-controller.ts:355 [log] > [stream-controller]: Media seeking to 0.100, state: IDLE, in buffer
base-stream-controller.ts:355 [log] > [audio-stream-controller]: Media seeking to 0.100, state: STOPPED, in buffer
base-stream-controller.ts:355 [log] > [subtitle-stream-controller]: Media seeking to 0.100, state: IDLE, in buffer
stream-controller.ts:573 [log] > [stream-controller]: Media seeked to 0.100
gap-controller.ts:520  [warn] > [gap-controller]: Playback stalling at @5.867472 due to low buffer ({"len":0.07681499999999986,"start":0.023223,"end":5.944287,"buffered":[{"start":0.023223,"end":5.944287}],"bufferedIndex":0})
_reportStall @ gap-controller.ts:520
poll @ gap-controller.ts:317
tick @ gap-controller.ts:147
setInterval
setInterval @ task-loop.ts:71
onMediaAttached @ gap-controller.ts:84
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
BufferController._this2._onMediaSourceOpen @ buffer-controller.ts:1555
interstitials-controller.ts:2878 [log] > [interstitials]: Primary player stall @5.867472 bufferedPos: 5.944287
latency-controller.ts:205  [warn] > [latency-controller]: Stall detected, adjusting target latency
onError @ latency-controller.ts:205
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
_reportStall @ gap-controller.ts:521
poll @ gap-controller.ts:317
tick @ gap-controller.ts:147
setInterval
setInterval @ task-loop.ts:71
onMediaAttached @ gap-controller.ts:84
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
BufferController._this2._onMediaSourceOpen @ buffer-controller.ts:1555
level-controller.ts:655 [log] > [level-controller]: Loading level index 0 age 12.0 EVENT http://***/main.m3u8
base-playlist-controller.ts:216 [log] > [level-controller]: live playlist 0 REFRESHED 2--1
base-playlist-controller.ts:346 [log] > [level-controller]: reload live playlist 0bps in 5947 ms
stream-controller.ts:661 [log] > [stream-controller]: Level 0 loaded [0,2][part-2--1], cc [0, 0] duration:18.023222222222223
buffer-controller.ts:1352 [log] > [buffer-controller]: Updating MediaSource duration to 18.023
base-stream-controller.ts:965 [log] > [stream-controller]: Loading main sn: 1 of level 0 (frag:[6.023-12.023]) cc: 0 [0-2], target: 6.023
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [stream-controller]: Loaded main sn: 1 of level 0
base-stream-controller.ts:2230 [log] > [stream-controller]: FRAG_LOADING->PARSING
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: 1 of level 0 cc: 0
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: 1 of level 0 cc: 0
transmuxer-interface.ts:396 [log] > [transmuxer.ts]: Flushed main sn: 1 of level 0
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:2177 [log] > [stream-controller]: Parsed main sn: 1 of level 0 (frag:[5.944-12.023])
base-stream-controller.ts:768 [log] > [stream-controller]: Buffered main sn: 1 of level 0 (frag:[5.944-12.023] > buffer:[0.023-11.958])
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:965 [log] > [stream-controller]: Loading main sn: 2 of level 0 (frag:[11.935-17.935]) cc: 0 [0-2], target: 11.958
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->FRAG_LOADING
gap-controller.ts:338 [log] > [gap-controller]: playback not stuck anymore @5.9533, after 5742ms
base-stream-controller.ts:537 [log] > [stream-controller]: Loaded main sn: 2 of level 0
base-stream-controller.ts:2230 [log] > [stream-controller]: FRAG_LOADING->PARSING
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: 2 of level 0 cc: 0
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: 2 of level 0 cc: 0
transmuxer-interface.ts:396 [log] > [transmuxer.ts]: Flushed main sn: 2 of level 0
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:2177 [log] > [stream-controller]: Parsed main sn: 2 of level 0 (frag:[11.958-18.023])
base-stream-controller.ts:768 [log] > [stream-controller]: Buffered main sn: 2 of level 0 (frag:[11.958-18.023] > buffer:[0.023-17.949])
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSED->IDLE

(It now plays without any problems, so similar logs continue.)

Chrome media internals output

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    Status

    Nice to have

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions