hls.js icon indicating copy to clipboard operation
hls.js copied to clipboard
verified publisher icon video-dev

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

Open xtne6f opened this issue 4 months ago • 5 comments

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

  • [x] The issue observed is not already reported by searching on Github under https://github.com/video-dev/hls.js/issues
  • [x] The issue occurs in the stable client (latest release) on https://hlsjs.video-dev.org/demo and not just on my page
  • [x] The issue occurs in the latest client (main branch) on https://hlsjs-dev.video-dev.org/demo and not just on my page
  • [x] The stream has correct Access-Control-Allow-Origin headers (CORS)
  • [x] There are no network errors such as 404s in the browser console when trying to play the stream

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 88be7874198d146c71600cc594360d064ad308bb, 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

xtne6f avatar Sep 24 '25 17:09 xtne6f

So if any live media playlist (not low-latency HLS blocking reload and not a Multivariant playlist), then the reload interval is doubled for the first live reload?

robwalch avatar Sep 24 '25 18:09 robwalch

So if any live media playlist (not low-latency HLS blocking reload and not a Multivariant playlist), then the reload interval is doubled for the first live reload?

Yes, that's right. I haven't checked the behavior in the Multivariant case, but this problem may not occur because the instances of levelDetails.requestScheduled (playlist-loader.ts) and details.requestScheduled (base-playlist-controller.ts) will be separate.

xtne6f avatar Sep 24 '25 18:09 xtne6f

Then if the media playlist has only one segment and autoplays, it will stall in one target (segment) duration for one target duration (plus overhead like roundtrip and append time). After that, however, the distance from the live edge will be correct. Playback shouldn't start until there are 3 segments in the playlist.

A client that joins when the playlist has only two segments, in the same situation, might stall briefly before the update that adds the third and forth segments. Even if fixed, this issue would still produce this brief stall in the first scenario (see related issue #7453).

Set initialLiveManifestSize to 3 to prevent smaller playlists from being used.

robwalch avatar Sep 24 '25 19:09 robwalch

This seems to be because handleTrackOrLevelPlaylist() (playlist-loader.ts) and playlistLoaded() (base-playlist-controller.ts) add the result of computeReloadInterval() to details.requestScheduled twice.

That's right. It looks like this would be fixed by changing handleTrackOrLevelPlaylist to set the initial scheduled time to the start time only.

- levelDetails.requestScheduled =
-        stats.loading.start + computeReloadInterval(levelDetails, 0);
+ levelDetails.requestScheduled = stats.loading.start;

robwalch avatar Sep 24 '25 19:09 robwalch

@robwalch Thank you for confirming! I also think there is no need to hurry to fix the issue. 1.7.0 milestone is enough. The proposed workaround (initialLiveManifestSize) works effectively.

That's right. It looks like this would be fixed by changing handleTrackOrLevelPlaylist to set the initial scheduled time to the start time only.

As far as I've tested, the fix doesn't seem to solve the issue. It makes the following if condition true: https://github.com/video-dev/hls.js/blob/v1.6.13/src/controller/base-playlist-controller.ts#L340 Therefore, 6 seconds are added to requestScheduled first, then another 3 seconds (this is also the result of computeReloadInterval()) are added. As a result, playback seems to stall for 3 seconds.

xtne6f avatar Sep 25 '25 15:09 xtne6f