BufferStalledError from the demo

ROBERT-MCDOWELL commented 2 years ago

What version of Hls.js are you using?

LAST

What browser (including version) are you using?

All browsers

What OS (including version) are you using?

All OS

Test stream

https://hls-js-bbdf933d-da48-407d-aaf3-68cc4ee058e7.netlify.app/demo/?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==

Configuration

{
  "debug": true,
  "enableWorker": true,
  "lowLatencyMode": true,
  "backBufferLength": 90
}

Additional player setup steps

No response

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://hls-js.netlify.com/demo and not just on my page
[X] The issue occurs in the latest client (main branch) on https://hls-js-dev.netlify.com/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

Play demo without changes

....

Expected behaviour

buffer must be filled better

What actually happened?

I tested the demo with the first video on the list and the rest untouched and I get bufferStalledError on all browsers last vevrsion on a 100Mb/s line where I everyday watch multiple simultaneous HD streaming from YT any clue why I get so many buffer error?

Console output

shls.js:4125 [log] > [stream-controller]: FRAG_LOADING->PARSING
4610d57f-1499-4a37-a180-8835f9262d5e:948 [log] > [transmuxer.ts]: Flushed fragment 8 of level 4
hls.js:4125 [log] > [stream-controller]: PARSING->PARSED
hls.js:3369 [log] > [stream-controller]: Buffered main sn: 8 of level 4 [0.023,90.001]
hls.js:4125 [log] > [stream-controller]: PARSED->IDLE
hls.js:3438 [log] > [stream-controller]: Loading fragment 9 cc: 0 of [0-63] level: 4, target: 90.001
hls.js:4125 [log] > [stream-controller]: IDLE->FRAG_LOADING
hls.js:3255 [log] > [stream-controller]: Loaded fragment 9 of level 4
4610d57f-1499-4a37-a180-8835f9262d5e:948 [log] > [transmuxer.ts]: Flushed fragment 9 of level 4
hls.js:4125 [log] > [stream-controller]: FRAG_LOADING->PARSING
hls.js:4125 [log] > [stream-controller]: PARSING->PARSED
hls.js:3369 [log] > [stream-controller]: Buffered main sn: 9 of level 4 [0.023,100.008]
hls.js:4125 [log] > [stream-controller]: PARSED->IDLE
hls.js:7631 [warn] > Playback stalling at @12.996104 due to low buffer ({"len":87.012239,"start":0.023222,"end":100.008343})
_reportStall @ hls.js:7631
poll @ hls.js:7559
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls.js:8230 [warn] > [playback-rate-controller]: Stall detected, adjusting target latency
onError @ hls.js:8230
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
_reportStall @ hls.js:7632
poll @ hls.js:7559
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls-demo.js:2148 Error event: {type: 'mediaError', details: 'bufferStalledError', fatal: false, buffer: 87.012239}
(anonymous) @ hls-demo.js:2148
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
_reportStall @ hls.js:7632
poll @ hls.js:7559
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls.js:7607 [warn] > Trying to nudge playhead over buffer-hole
_tryFixBufferStall @ hls.js:7607
poll @ hls.js:7568
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls.js:7711 [warn] > Nudging 'currentTime' from 12.996104 to 13.096104
_tryNudgeBuffer @ hls.js:7711
_tryFixBufferStall @ hls.js:7613
poll @ hls.js:7568
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls-demo.js:2148 Error event: {type: 'mediaError', details: 'bufferNudgeOnStall', fatal: false}
(anonymous) @ hls-demo.js:2148
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
_tryNudgeBuffer @ hls.js:7713
_tryFixBufferStall @ hls.js:7613
poll @ hls.js:7568
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140
hls.js:3130 [log] > [stream-controller]: media seeking to 13.096, state: IDLE
hls.js:3130 [log] > [audio-stream-controller]: media seeking to 13.096, state: STOPPED
hls.js:3130 [log] > [subtitle-stream-controller]: media seeking to 13.096, state: IDLE
hls.js:10062 [log] > [stream-controller]: Media seeked to 13.096
hls.js:7483 [warn] > playback not stuck anymore @13.113104, after 50ms
poll @ hls.js:7483
checkBuffer @ hls.js:10425
onTickEnd @ hls.js:9757
doTick @ hls.js:9751
tick @ hls.js:22845
setInterval (async)
setInterval @ hls.js:22800
startLoad @ hls.js:9660
(anonymous) @ hls.js:17716
startLoad @ hls.js:17715
onManifestLoaded @ hls.js:8611
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
handleMasterPlaylist @ hls.js:20678
loadsuccess @ hls.js:20602
readystatechange @ hls.js:28762
XMLHttpRequest.send (async)
loadInternal @ hls.js:28696
load @ hls.js:28637
load @ hls.js:20575
onManifestLoading @ hls.js:20428
emit @ hls.js:310
emit @ hls.js:17604
trigger @ hls.js:17609
loadSource @ hls.js:17696
loadSelectedStream @ hls-demo.js:1828
applyConfigEditorValue @ hls-demo.js:3032
onclick @ ?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==:140

Chrome media internals output

No response

robwalch commented 2 years ago

According to the logs the buffer is provisioned. The stall is likely reported because the player is observing that currentTime has not changed for more than a certain threshold.

ROBERT-MCDOWELL commented 2 years ago

ok so does it mean the player is too much redundant?

robwalch commented 1 year ago

hls.js:7631 [warn] > Playback stalling at @12.996104 due to low buffer ({"len":87.012239,"start":0.023222,"end":100.008343})
_reportStall @ hls.js:7631
poll @ hls.js:7559
checkBuffer @ hls.js:10425

This means that the stall event was fired at 12.9s of playback with 87 seconds of buffer available by checkBuffer. It would only do this if the browser you are running failed to update currentTime between multiple checks for a certain period. Yes it is too redundant and should rely more prominently on waiting and canplay events and only fallback to currentTime observation when these events do not fire or the playback is not advancing on or near a buffer gap.

robwalch commented 1 year ago

I've observed similar behavior in Chrome 107-108. It might be related to JavaScript throttling or some other internal issue. Restarting Chrome clears things up.

ROBERT-MCDOWELL commented 1 year ago

@robwalch thanks for the clarification. weird it's also happening on last chrome versions.... did not know there is such kind of throttle for javascript.... is it also possible that the GPU / CPU busy for something else has not enough speed/time to interpret the jS?

robwalch commented 1 year ago

it's possible

robwalch commented 1 year ago

Related to #4884

4884

ROBERT-MCDOWELL commented 1 year ago

do you think a compromise can be done from the code? I close the issue?

video-dev / hls.js