hls.js 1.5 plays out the bandwidth test fragment

[barnslig]

Hello everyone, thank you for the great library!

I found a problem when upgrading from hls.js 1.4.14 to 1.5.8. Starting with 1.5.0, for the first few seconds, my videos are played back in the lowest possible quality. My expectation would be that the first fragment is only loaded for bandwidth measurement and not displayed.

I tested the behaviour on the demo page at https://hlsjs.video-dev.org/demo/ and could reproduce the problem. However, it only seems to appear with my specific stream and not for example with the "Big Buck Bunny - adaptive qualities" stream.

Unfortunately, I cannot share a stream URL. However, I tried to attach as much information as possible.

My hls.js settings are as follows:

{
  "startLevel": -1,
}

The m3u8 playlist looks as follows:

Details

#EXTM3U
#EXT-X-MEDIA:TYPE=VIDEO,URI="192/index.m3u8", GROUP-ID="384x216@2.000-24000",NAME="Video0",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="420/index.m3u8", GROUP-ID="400x224@25.000-420000",NAME="Video1",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="800/index.m3u8", GROUP-ID="640x360@25.000-768000",NAME="Video2",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="1300/index.m3u8", GROUP-ID="640x360@25.000-1300000",NAME="Video3",DEFAULT=YES,AUTOSELECT=YES
#EXT-X-MEDIA:TYPE=VIDEO,URI="2200/index.m3u8", GROUP-ID="768x432@25.000-2200000",NAME="Video4",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="3400/index.m3u8", GROUP-ID="1280x720@25.000-3400000",NAME="Video5",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="6000/index.m3u8", GROUP-ID="1920x1080@25.000-6000000",NAME="Video6",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-MEDIA:TYPE=VIDEO,URI="9000/index.m3u8", GROUP-ID="1920x1080@25.000-9000000",NAME="Video7",DEFAULT=NO,AUTOSELECT=NO
#EXT-X-STREAM-INF:BANDWIDTH=9380484,CODECS="avc1.4d4028,mp4a.40.2",RESOLUTION=1920x1080,FRAME-RATE=25.000
9000/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=192057,CODECS="avc1.42c00c,mp4a.40.2",RESOLUTION=384x216,FRAME-RATE=2.000
192/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=613962,CODECS="avc1.4d4014,mp4a.40.2",RESOLUTION=400x224,FRAME-RATE=25.000
420/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=969527,CODECS="avc1.4d401e,mp4a.40.2",RESOLUTION=640x360,FRAME-RATE=25.000
800/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=1513092,CODECS="avc1.4d401e,mp4a.40.2",RESOLUTION=640x360,FRAME-RATE=25.000
1300/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=2432658,CODECS="avc1.4d401e,mp4a.40.2",RESOLUTION=768x432,FRAME-RATE=25.000
2200/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=3658745,CODECS="avc1.4d4020,mp4a.40.2",RESOLUTION=1280x720,FRAME-RATE=25.000
3400/index.m3u8
#EXT-X-STREAM-INF:BANDWIDTH=6315266,CODECS="avc1.4d4028,mp4a.40.2",RESOLUTION=1920x1080,FRAME-RATE=25.000
6000/index.m3u8

In the real-time metrics, one can see that a fragment from the lowest quality is played back for a short amount of time:

The debug log looks as follows. One can see that abr initially switches from quality 7 to quality 0, which has not happened with hls.js 1.4.14.

Details

[log] > Debug logs enabled for "Hls instance" in hls.js version 1.5.8
hls.ts:442 [log] > stopLoad
hls.ts:410 [log] > loadSource:https://xxxxx/vod/WW/xxxxx/hd/index.m3u8
stream-controller.ts:576 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:380 [log] > attachMedia
buffer-controller.ts:198 [log] > [buffer-controller] created media source: MediaSource
buffer-controller.ts:994 [log] > [buffer-controller] Media source opened
level-controller.ts:337 [log] > [level-controller]: manifest loaded, 8 level(s) found, first bitrate: 9380484
abr-controller.ts:58 [log] > setting initial bwe to 9380484
buffer-controller.ts:186 [log] > [buffer-controller] 1 bufferCodec event(s) expected
abr-controller.ts:701 [log] > [abr] picked start tier {"codecSet":"avc1,mp4a","videoRanges":["SDR"],"preferHDR":false,"minFramerate":2,"minBitrate":192057}
abr-controller.ts:855 [info] > [abr] switch candidate:7->0 adjustedbw(9380484)-bitrate=9188427 ttfb:0.1 avgDuration:0.0 maxFetchDuration:4.0 fetchDuration:0.1 firstSelection:true codecSet:avc1,mp4a videoRange:SDR hls.loadLevel:-1
hls.ts:431 [log] > startLoad(-1)
level-controller.ts:432 [log] > [level-controller]: Switching to level 0 (216p SDR avc1,mp4a @192057) from level -1
level-controller.ts:600 [log] > [level-controller]: Loading level index 0 with https://xxxxx/vod/WW/xxxxx/hd/192/index.m3u8
base-stream-controller.ts:1781 [log] > [stream-controller]: STOPPED->IDLE
base-stream-controller.ts:1781 [log] > [subtitle-stream-controller]: STOPPED->IDLE
stream-controller.ts:639 [log] > [stream-controller]: Level 0 loaded [0,616][part-616--1], cc [0, 0] duration:3700
buffer-controller.ts:861 [log] > [buffer-controller] Updating Media Source duration to 3700.000
stream-controller.ts:374 [log] > [stream-controller]: Fragment 0 of level 0 is being downloaded to test bitrate and will not be buffered
base-stream-controller.ts:748 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-616] level: 0, target: 0
base-stream-controller.ts:1781 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1781 [log] > [stream-controller]: FRAG_LOADING->IDLE
abr-controller.ts:701 [log] > [abr] picked start tier {"codecSet":"avc1,mp4a","videoRanges":["SDR"],"preferHDR":false,"minFramerate":2,"minBitrate":192057}
base-stream-controller.ts:1025 [warn] > [stream-controller]: Reduce max buffer length to 300s
reduceMaxBufferLength @ base-stream-controller.ts:1025
clearTrackerIfNeeded @ base-stream-controller.ts:419
loadFragment @ stream-controller.ts:383
doTickIdle @ stream-controller.ts:356
doTick @ stream-controller.ts:211
tick @ task-loop.ts:106
setInterval (async)
setInterval @ task-loop.ts:68
startLoad @ stream-controller.ts:127
(anonymous) @ hls.ts:434
startLoad @ hls.ts:433
filterAndSortMediaOptions @ level-controller.ts:376
onManifestLoaded @ level-controller.ts:200
emit @ index.js:203
emit @ hls.ts:310
trigger @ hls.ts:318
handleMasterPlaylist @ playlist-loader.ts:429
onSuccess @ playlist-loader.ts:327
readystatechange @ xhr-loader.ts:239
XMLHttpRequest.send (async)
openAndSendXhr @ xhr-loader.ts:166
loadInternal @ xhr-loader.ts:125
load @ xhr-loader.ts:84
load @ playlist-loader.ts:352
onManifestLoading @ playlist-loader.ts:154
emit @ index.js:203
emit @ hls.ts:310
trigger @ hls.ts:318
loadSource @ hls.ts:420
loadSelectedStream @ main.js:372
(anonymous) @ main.js:225
j @ jquery.min.js:2
fireWith @ jquery.min.js:2
ready @ jquery.min.js:2
I @ jquery.min.js:2
Show 2 more frames
Show less
base-stream-controller.ts:748 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-616] level: 0, target: 0
base-stream-controller.ts:1781 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:89 [log] > injecting Web Worker for "main"
transmuxer-interface.ts:231 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 0 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:389 [log] > [stream-controller]: Loaded fragment 0 of level 0
23ac11f7-1d75-4e3e-bbbc-dca838627b94:555 [log] > Debug logs enabled for "main" in hls.js version 1.5.8
transmuxer-interface.ts:383 [log] > [mp4-remuxer]: ISGenerated flag reset
transmuxer-interface.ts:383 [log] > [mp4-remuxer]: initPTS & initDTS reset
transmuxer-interface.ts:383 [log] > [mp4-remuxer]: reset next timestamp
transmuxer-interface.ts:383 [log] > manifest codec:mp4a.40.2, ADTS type:2, samplingIndex:3
transmuxer-interface.ts:383 [log] > parsed codec:mp4a.40.5, rate:48000, channels:2
base-stream-controller.ts:1781 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1297 [log] > [stream-controller]: Init audio buffer, container:audio/mp4, codecs[selected/level/parsed]=[mp4a.40.2/mp4a.40.2/mp4a.40.5]
stream-controller.ts:1308 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.42c00c/avc1.42c00c]
buffer-controller.ts:393 [log] > [buffer-controller] 0 bufferCodec event(s) expected audio,video
buffer-controller.ts:943 [log] > [buffer-controller] creating sourceBuffer(audio/mp4;codecs=mp4a.40.2)
buffer-controller.ts:943 [log] > [buffer-controller] creating sourceBuffer(video/mp4;codecs=avc1.42c00c)
audio-stream-controller.ts:134 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 900000
transmuxer-interface.ts:383 [log] > [transmuxer.ts]: Flushed fragment 0 of level 0
base-stream-controller.ts:1781 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:560 [log] > [stream-controller]: Buffered main sn: 0 of level 0 (frag:[0.000-6.000] > buffer:[0.000-5.995])
base-stream-controller.ts:1781 [log] > [stream-controller]: PARSED->IDLE
abr-controller.ts:855 [info] > [abr] switch candidate:0->6 adjustedbw(8196195)-bitrate=1880929 ttfb:0.0 avgDuration:6.0 maxFetchDuration:6.0 fetchDuration:4.7 firstSelection:false codecSet:avc1,mp4a videoRange:SDR hls.loadLevel:0
stream-controller.ts:268 [log] > [stream-controller]: Adapting to level 6 from level 0
level-controller.ts:432 [log] > [level-controller]: Switching to level 6 (1080p SDR avc1,mp4a @6315266) from level 0
level-controller.ts:600 [log] > [level-controller]: Loading level index 6 with https://xxxxx/vod/WW/xxxxx/hd/6000/index.m3u8
base-stream-controller.ts:1781 [log] > [stream-controller]: IDLE->WAITING_LEVEL
stream-controller.ts:639 [log] > [stream-controller]: Level 6 loaded [0,616][part-616--1], cc [0, 0] duration:3699.819
base-stream-controller.ts:1781 [log] > [stream-controller]: WAITING_LEVEL->IDLE
base-stream-controller.ts:748 [log] > [stream-controller]: Loading fragment 1 cc: 0 of [0-616] level: 6, target: 6
base-stream-controller.ts:1781 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:231 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 1 p: -1 level: 6 id: 1
        discontinuity: false
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 6
        initSegmentChange: false
...

Does anybody have an idea why the low quality is chosen for a short amount of time?

[robwalch]

The lowest bitrate variant says it has a frame-rate of 2 (FRAME-RATE=2.000). Is this intentional and correct?

This could be impacting the initial selection. What happens if you disable the bitrate test?

If you are always getting startup on the lowest frame-rate, and that rate is less than 30fps, please file a bug.

[barnslig]

Thank you for the quick response!

We have some old videos which indeed have a super-low bitrate version with 2 fps, which is more like an audio fallback. Newer videos have 420px width / 25 fps as the lowest level, which seems not to trigger the bug.

It seems that the bug is indeed related to the low bit rate. The bug also appears when I leave startLevel on the default value.

As a workaround, I removed the 2 fps level within the MANIFEST_PARSED event callback using hls.removeLevel. Using the workaround, the bug no longer appears and the correct level is played out after the initial bandwidth check.

[robwalch]

Thanks for confirming and providing a workaround.

Please file a bug so that we can schedule a fix.