Video freezes on rendition switch in LLHLS #5111

erankor · 2022-12-15T16:07:33Z

What version of Hls.js are you using?

v1.2.5-0.canary.8760

What browser (including version) are you using?

Version 108.0.5359.124 (Official Build) (64-bit)

What OS (including version) are you using?

Windows 10

Test stream

https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/master-s35-s34-s33-s42-s32-s43.m3u8

Configuration

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

Additional player setup steps

No response

Checklist

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

Steps to reproduce

Play the provided test stream, and occasionally change the video quality using the quality selector

Expected behaviour

The video would play smoothly

What actually happened?

The video freezes for ~3 sec on every quality switch.
I noticed that rendition reports are not used, since we are omitting attributes from EXT-X-RENDITION-REPORT tags, and opened #5110. This PR fixes the rendition reports issue (I no longer see a request for a playlist without _HLS_msn / _HLS_part after the fix), but the freeze issue remains.

Console output

main.js:341 Using Hls.js config: Object
logger.ts:74 [log] > Debug logs enabled for "Hls instance"
hls.ts:372 [log] > stopLoad
hls.ts:340 [log] > loadSource:https://test-streams.mux.dev/x36xhzz/x36xhzz.m3u8
stream-controller.ts:537 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:311 [log] > attachMedia
level-controller.ts:172 [log] > [level-controller]: manifest loaded, 5 level(s) found, first bitrate: 2149280
buffer-controller.ts:136 [log] > 1 bufferCodec event(s) expected
hls.ts:362 [log] > startLoad(-1)
level-controller.ts:251 [log] > [level-controller]: switching to level 3 from -1
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 3 with URL-id 0 https://test-streams.mux.dev/x36xhzz/url_0/193039199_mp4_h264_aac_hd_7.m3u8
base-stream-controller.ts:1460 [log] > [stream-controller]: STOPPED->IDLE
base-stream-controller.ts:1460 [log] > [subtitle-stream-controller]: STOPPED->IDLE
stream-controller.ts:602 [log] > [stream-controller]: Level 3 loaded [0,63], cc [0, 0] duration:634.584
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 634.584
buffer-controller.ts:756 [log] > [buffer-controller]: Media source opened
base-stream-controller.ts:642 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-63] level: 3, target: 0
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:68 [log] > demuxing in webworker
transmuxer-interface.ts:201 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 0 p: -1 level: 3 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:360 [log] > [stream-controller]: Loaded fragment 0 of level 3
blob:https://hls-js-dev.netlify.app/72018c3a-4531-41b0-8c74-e0310e117a33:540 [log] > Debug logs enabled for "main"
transmuxer-interface.ts:307 [log] > [mp4-remuxer]: ISGenerated flag reset
transmuxer-interface.ts:307 [log] > [mp4-remuxer]: initPTS & initDTS reset
transmuxer-interface.ts:307 [log] > manifest codec:mp4a.40.2, ADTS type:2, samplingIndex:4
transmuxer-interface.ts:307 [log] > parsed codec:mp4a.40.5, rate:44100, channels:2
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1225 [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:1236 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.64001f/avc1.64001f]
buffer-controller.ts:717 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2)
buffer-controller.ts:717 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.64001f)
audio-stream-controller.ts:113 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 900909
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 0 of level 3
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 0 of level 3 [0.023,10.008]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
level-controller.ts:251 [log] > [level-controller]: switching to level 4 from 3
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 4 with URL-id 0 https://test-streams.mux.dev/x36xhzz/url_8/193039199_mp4_h264_aac_fhd_7.m3u8
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->WAITING_LEVEL
stream-controller.ts:602 [log] > [stream-controller]: Level 4 loaded [0,63], cc [0, 0] duration:634.567
base-stream-controller.ts:1460 [log] > [stream-controller]: WAITING_LEVEL->IDLE
base-stream-controller.ts:642 [log] > [stream-controller]: Loading fragment 1 cc: 0 of [0-63] level: 4, target: 10.008
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
favicon.ico:1          GET https://hls-js-dev.netlify.app/favicon.ico 404 (Not Found)
hls.ts:292 [log] > destroy
hls.ts:320 [log] > detachMedia
buffer-controller.ts:162 [log] > [buffer-controller]: media source detaching
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->STOPPED
base-stream-controller.ts:1460 [log] > [subtitle-stream-controller]: IDLE->STOPPED
main.js:341 Using Hls.js config: {debug: true, enableWorker: true, lowLatencyMode: true, backBufferLength: 90}
logger.ts:74 [log] > Debug logs enabled for "Hls instance"
hls.ts:372 [log] > stopLoad
hls.ts:340 [log] > loadSource:https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/master-s35-s34-s33-s42-s32-s43.m3u8
stream-controller.ts:537 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:311 [log] > attachMedia
buffer-controller.ts:756 [log] > [buffer-controller]: Media source opened
base-stream-controller.ts:1460 [log] > [subtitle-stream-controller]: STOPPED->IDLE
level-controller.ts:172 [log] > [level-controller]: manifest loaded, 6 level(s) found, first bitrate: 979309
buffer-controller.ts:136 [log] > 2 bufferCodec event(s) expected
hls.ts:362 [log] > startLoad(-1)
level-controller.ts:251 [log] > [level-controller]: switching to level 2 from -1
audio-track-controller.ts:134 [log] > [audio-track-controller]: Updating audio tracks, 1 track(s) found in "aud6" group-id
audio-track-controller.ts:185 [log] > [audio-track-controller]: Now switching to audio-track index 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: STOPPED->IDLE
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_TRACK
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 2 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s35-v.m3u8
base-stream-controller.ts:1460 [log] > [stream-controller]: STOPPED->IDLE
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_TRACK->STOPPED
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: STOPPED->WAITING_TRACK
base-stream-controller.ts:1460 [log] > [subtitle-stream-controller]: IDLE->STOPPED
base-stream-controller.ts:1460 [log] > [subtitle-stream-controller]: STOPPED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 2 at sn 93181158 part 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s35-v.m3u8?_HLS_msn=93181158&_HLS_part=1&_HLS_skip=YES
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->WAITING_LEVEL
stream-controller.ts:602 [log] > [stream-controller]: Level 2 loaded [93179956,93181157], cc [0, 0] duration:7195.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: na->93179956 prev-sn: na fragments: 1202
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7195.851
base-stream-controller.ts:1460 [log] > [stream-controller]: WAITING_LEVEL->IDLE
base-stream-controller.ts:642 [log] > [stream-controller]: Loading fragment initSegment cc: 0 of [93179956-93181157] level: 2, target: 0
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 MISSED
base-playlist-controller.ts:239 [log] > [audio-track-controller]: reload live playlist 0 in 4000 ms
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179956,93181157],duration:7195.851000000006
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_TRACK->IDLE
base-stream-controller.ts:642 [log] > [audio-stream-controller]: Loading fragment initSegment cc: 0 of [93179956-93181157] track: 0, target: 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: initSegment of level 2 
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181157 p: 3 cc: 0 of playlist [93179956-93181157] parts [0-21-24] level: 2, target: 7192.864
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: initSegment of track 0 
audio-stream-controller.ts:827 [log] > [audio-stream-controller]: Waiting for video PTS in continuity counter 0 of live stream before loading audio fragment 93181157 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_INIT_PTS
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_INIT_PTS->IDLE
audio-stream-controller.ts:827 [log] > [audio-stream-controller]: Waiting for video PTS in continuity counter 0 of live stream before loading audio fragment 93181157 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_INIT_PTS
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_INIT_PTS->IDLE
audio-stream-controller.ts:827 [log] > [audio-stream-controller]: Waiting for video PTS in continuity counter 0 of live stream before loading audio fragment 93181157 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_INIT_PTS
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_INIT_PTS->IDLE
audio-stream-controller.ts:827 [log] > [audio-stream-controller]: Waiting for video PTS in continuity counter 0 of live stream before loading audio fragment 93181157 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_INIT_PTS
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_INIT_PTS->IDLE
transmuxer-interface.ts:68 [log] > demuxing in webworker
transmuxer-interface.ts:201 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 93181157 p: 3 level: 2 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7191.851000000006
        initSegmentChange: true
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181158-1
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179956,93181157],duration:7196.851000000006
audio-stream-controller.ts:827 [log] > [audio-stream-controller]: Waiting for video PTS in continuity counter 0 of live stream before loading audio fragment 93181157 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->WAITING_INIT_PTS
0c0ed6cb-51e5-438a-b71a-4e4d5d6a96ce:540 [log] > Debug logs enabled for "main"
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1236 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.4d4016/avc1.4d4016]
audio-stream-controller.ts:113 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 1237.1989999999932
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: WAITING_INIT_PTS->IDLE
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181157 p: 4 cc: 0 of playlist [93179956-93181157] parts [0-22-25] track: 0, target: 7192.868
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 2 REFRESHED 93181158-1
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 2 at sn 93181158 part 2 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s35-v.m3u8?_HLS_msn=93181158&_HLS_part=2&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 2 loaded [93179956,93181157], cc [0, 0] duration:7196.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: 93179956->93179956 prev-sn: na fragments: 1202
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7196.851
transmuxer-interface.ts:68 [log] > demuxing in webworker
transmuxer-interface.ts:201 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 93181157 p: 4 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7192.85100000001
        initSegmentChange: true
3c41c066-f94f-4e28-bb29-5adfd322948e:540 [log] > Debug logs enabled for "audio"
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
audio-stream-controller.ts:841 [log] > [audio-stream-controller]: Switching audio track : flushing all audio
audio-stream-controller.ts:789 [log] > [audio-stream-controller]: Init audio buffer, container:audio/mp4, codecs[parsed]=[mp4a.40.2]
buffer-controller.ts:717 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.4d4016)
buffer-controller.ts:717 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2)
stream-controller.ts:809 [log] > [stream-controller]: Alternate track found, use video.buffered to schedule main fragment loading
buffer-controller.ts:830 [log] > [buffer-controller]: Removing [0,7196.851000000006] from the audio SourceBuffer
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181157 p: 5 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181157 part: 5 of track 0 [7192.863,7194.859]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181157 p: 5 of level 2
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181157 part: 5 of level 2 [7191.851,7194.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
stream-controller.ts:989 [log] > [stream-controller]: seek to target start position 7192.86489990235 from current time 0
level-controller.ts:251 [log] > [level-controller]: switching to level 0 from 2
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8
playlist-loader.ts:225 [log] > [playlist-loader]: aborting previous loader for type: level
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->WAITING_LEVEL
base-stream-controller.ts:223 [log] > [stream-controller]: media seeking to 7192.865, state: WAITING_LEVEL
base-stream-controller.ts:223 [log] > [audio-stream-controller]: media seeking to 7192.865, state: IDLE
base-stream-controller.ts:223 [log] > [subtitle-stream-controller]: media seeking to 7192.865, state: IDLE
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181158 p: 0 cc: 0 of playlist [93179956-93181157] parts [0-24-25] track: 0, target: 7194.859
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181158 part 2 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181158&_HLS_part=2&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179956,93181157], cc [0, 0] duration:7196.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: na->93179956 prev-sn: 93181157 fragments: 1202
base-stream-controller.ts:1460 [log] > [stream-controller]: WAITING_LEVEL->IDLE
base-stream-controller.ts:642 [log] > [stream-controller]: Loading fragment initSegment cc: 0 of [93179956-93181157] level: 0, target: 0
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:528 [log] > [stream-controller]: Media seeked to 7192.867
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181158-2
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179956,93181157],duration:7197.851000000006
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: initSegment of level 0 [7191.851,7194.850]
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 0 cc: 0 of playlist [93179956-93181157] parts [0-24-25] level: 0, target: 7194.851
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 0 REFRESHED 93181158-2
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181158 part 3 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181158&_HLS_part=3&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179956,93181157], cc [0, 0] duration:7197.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: 93179956->93179956 prev-sn: 93181157 fragments: 1202
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7197.851
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 1 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181158 part: 1 of track 0 [7192.863,7196.856]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181158 p: 2 cc: 0 of playlist [93179956-93181157] parts [0-26-26] track: 0, target: 7196.856
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 2 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181158 part: 2 of track 0 [7192.863,7197.855]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
transmuxer-interface.ts:201 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 93181158 p: 0 level: 0 id: 1
        discontinuity: false
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7194.851000000006
        initSegmentChange: true
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1236 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.4d4015/avc1.4d4015]
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 1 of level 0
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 1 of level 0 [7191.851,7196.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 2 cc: 0 of playlist [93179956-93181157] parts [0-26-26] level: 0, target: 7196.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 2 of level 0
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 2 of level 0 [7191.851,7197.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181158-3
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179956,93181157],duration:7198.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181158 p: 3 cc: 0 of playlist [93179956-93181157] parts [0-27-27] track: 0, target: 7197.855
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 0 REFRESHED 93181158-3
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181158 part 4 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181158&_HLS_part=4&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179956,93181157], cc [0, 0] duration:7198.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: 93179956->93179956 prev-sn: 93181158 fragments: 1202
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 3 cc: 0 of playlist [93179956-93181157] parts [0-27-27] level: 0, target: 7197.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7198.851
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 3 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181158 part: 3 of track 0 [7192.863,7198.853]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 3 of level 0
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 3 of level 0 [7191.851,7198.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 0 REFRESHED 93181158-4
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181158 part 5 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181158&_HLS_part=5&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179956,93181157], cc [0, 0] duration:7199.851000000006
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 0.00 start-sn: 93179956->93179956 prev-sn: 93181158 fragments: 1202
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 4 cc: 0 of playlist [93179956-93181157] parts [0-28-28] level: 0, target: 7198.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7199.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179956-93181157]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181158-4
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179956,93181157],duration:7199.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181158 p: 4 cc: 0 of playlist [93179956-93181157] parts [0-28-28] track: 0, target: 7198.853
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 4 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181158 part: 4 of track 0 [7192.863,7199.852]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 4 of level 0
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 4 of level 0 [7191.851,7199.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181158-5
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7194.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181158 p: 5 cc: 0 of playlist [93179957-93181158] parts [0-23-23] track: 0, target: 7199.852
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 0 REFRESHED 93181158-5
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181159 part 0 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181159&_HLS_part=0&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179957,93181158], cc [0, 0] duration:7194.851000000006
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 5 cc: 0 of playlist [93179957-93181158] parts [0-23-23] level: 0, target: 7199.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7200.851
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 5 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181158 part: 5 of track 0 [7192.863,7200.850]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 5 of level 0
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 5 of level 0 [7191.851,7200.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-0
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7195.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181159 p: 0 cc: 0 of playlist [93179957-93181158] parts [0-24-24] track: 0, target: 7200.851
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 0 REFRESHED 93181159-0
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 0 at sn 93181159 part 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s33-v.m3u8?_HLS_msn=93181159&_HLS_part=1&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 0 loaded [93179957,93181158], cc [0, 0] duration:7195.851000000006
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181159 p: 0 cc: 0 of playlist [93179957-93181158] parts [0-24-24] level: 0, target: 7200.851
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7201.851
hls.ts:428 [log] > set currentLevel:1
hls.ts:469 [log] > set loadLevel:1
level-controller.ts:251 [log] > [level-controller]: switching to level 1 from 0
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8
playlist-loader.ts:225 [log] > [playlist-loader]: aborting previous loader for type: level
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->IDLE
buffer-controller.ts:830 [log] > [buffer-controller]: Removing [0,7201.851000000006] from the video SourceBuffer
base-stream-controller.ts:1271 [warn] > [stream-controller]: Fragment 93181159 part0 of level 0 was aborted
handleFragLoadAborted @ base-stream-controller.ts:1271
handleFragLoadError @ base-stream-controller.ts:732
(anonymous) @ base-stream-controller.ts:631
Promise.catch (async)
_doFragLoad @ base-stream-controller.ts:631
_loadFragForPlayback @ base-stream-controller.ts:340
loadFragment @ base-stream-controller.ts:316
loadFragment @ stream-controller.ts:344
doTickIdle @ stream-controller.ts:323
doTick @ stream-controller.ts:165
tick @ task-loop.ts:110
onLevelLoaded @ stream-controller.ts:655
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
playlistLoaded @ base-playlist-controller.ts:203
onLevelLoaded @ level-controller.ts:487
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
playlistLoaded @ base-playlist-controller.ts:203
onLevelLoaded @ level-controller.ts:487
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
playlistLoaded @ base-playlist-controller.ts:203
onLevelLoaded @ level-controller.ts:487
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
playlistLoaded @ base-playlist-controller.ts:203
onLevelLoaded @ level-controller.ts:487
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
playlistLoaded @ base-playlist-controller.ts:203
onLevelLoaded @ level-controller.ts:487
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
handlePlaylistLoaded @ playlist-loader.ts:709
handleTrackOrLevelPlaylist @ playlist-loader.ts:546
loadsuccess @ playlist-loader.ts:346
readystatechange @ xhr-loader.ts:202
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:134
load @ xhr-loader.ts:72
load @ playlist-loader.ts:310
onLevelLoading @ playlist-loader.ts:168
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
loadPlaylist @ level-controller.ts:552
set @ level-controller.ts:268
set @ level-controller.ts:570
set @ hls.ts:487
doTickIdle @ stream-controller.ts:232
doTick @ stream-controller.ts:165
tick @ task-loop.ts:110
fragBufferedComplete @ base-stream-controller.ts:517
onFragBuffered @ stream-controller.ts:843
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
onUnblocked @ buffer-controller.ts:492
(anonymous) @ buffer-controller.ts:880
Promise.then (async)
blockBuffers @ buffer-controller.ts:878
onFragParsed @ buffer-controller.ts:506
emit @ index.js:203
emit @ hls.ts:251
trigger @ hls.ts:259
updateLevelTiming @ base-stream-controller.ts:1446
_handleTransmuxerFlush @ base-stream-controller.ts:753
onWorkerMessage @ transmuxer-interface.ts:300
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 0 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181159 part: 0 of track 0 [7192.863,7201.872]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
level-controller.ts:251 [log] > [level-controller]: switching to level 1 from 1
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->WAITING_LEVEL
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181159 part 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181159&_HLS_part=1&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179957,93181158], cc [0, 0] duration:7195.851000000006
discontinuities.ts:169 [log] > Adjusting PTS using programDateTime delta 0ms, sliding:6.000 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8 
base-stream-controller.ts:1198 [log] > [stream-controller]: Live playlist sliding: 6.00 start-sn: na->93179957 prev-sn: 93181158 fragments: 1202
base-stream-controller.ts:1460 [log] > [stream-controller]: WAITING_LEVEL->IDLE
base-stream-controller.ts:642 [log] > [stream-controller]: Loading fragment initSegment cc: 0 of [93179957-93181158] level: 1, target: 0
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: initSegment of level 1 
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181158 p: 0 cc: 0 of playlist [93179957-93181158] parts [0-18-24] level: 1, target: 7197.196
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:201 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 93181158 p: 0 level: 1 id: 1
        discontinuity: false
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7194.851000000006
        initSegmentChange: true
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1236 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.4d4016/avc1.4d4016]
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181159-1
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181159 part 2 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181159&_HLS_part=2&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179957,93181158], cc [0, 0] duration:7196.851000000006
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7202.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-1
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7196.851000000006
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-2
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7197.851000000006
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181159-2
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181159 part 3 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181159&_HLS_part=3&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179957,93181158], cc [0, 0] duration:7197.851000000006
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7203.851
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181159 p: 1 cc: 0 of playlist [93179957-93181158] parts [0-25-26] track: 0, target: 7201.872
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 2 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181159 part: 2 of track 0 [7192.863,7203.869]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181159-3
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181159 part 4 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181159&_HLS_part=4&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179957,93181158], cc [0, 0] duration:7198.851000000006
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7204.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-3
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7198.851000000006
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181158 p: 5 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181158 part: 5 of level 1 [7194.850,7200.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181159 p: 0 cc: 0 of playlist [93179957-93181158] parts [0-24-27] level: 1, target: 7200.851
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181159 p: 3 cc: 0 of playlist [93179957-93181158] parts [0-27-27] track: 0, target: 7203.869
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 3 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181159 part: 3 of track 0 [7192.863,7204.867]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181159-4
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181159 part 5 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181159&_HLS_part=5&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179957,93181158], cc [0, 0] duration:7199.851000000006
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7205.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179957-93181158]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-4
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179957,93181158],duration:7199.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181159 p: 4 cc: 0 of playlist [93179957-93181158] parts [0-28-28] track: 0, target: 7204.867
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 4 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181159 part: 4 of track 0 [7192.863,7205.866]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 3 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181159 part: 3 of level 1 [7194.850,7204.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181159 p: 4 cc: 0 of playlist [93179957-93181158] parts [0-28-28] level: 1, target: 7204.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181159-5
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181160 part 0 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181160&_HLS_part=0&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179958,93181159], cc [0, 0] duration:7194.851000000006
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7206.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179958-93181159]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181159-5
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179958,93181159],duration:7194.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181159 p: 5 cc: 0 of playlist [93179958-93181159] parts [0-23-23] track: 0, target: 7205.866
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 4 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181159 part: 4 of level 1 [7194.850,7205.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 5 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181159 part: 5 of track 0 [7192.863,7206.864]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181160-0
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181160 part 1 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181160&_HLS_part=1&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179958,93181159], cc [0, 0] duration:7195.851000000006
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181159 p: 5 cc: 0 of playlist [93179958-93181159] parts [0-23-24] level: 1, target: 7205.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7207.851
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179958-93181159]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181160-0
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179958,93181159],duration:7195.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181160 p: 0 cc: 0 of playlist [93179958-93181159] parts [0-24-24] track: 0, target: 7206.864
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181160 p: 0 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181160 part: 0 of track 0 [7192.863,7207.863]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181159 p: 5 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181159 part: 5 of level 1 [7194.850,7206.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181160 p: 0 cc: 0 of playlist [93179958-93181159] parts [0-24-24] level: 1, target: 7206.851
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181160 p: 0 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181160 part: 0 of level 1 [7194.850,7207.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179958-93181159]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181160-1
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179958,93181159],duration:7196.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181160 p: 1 cc: 0 of playlist [93179958-93181159] parts [0-25-25] track: 0, target: 7207.863
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181160-1
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181160 part 2 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181160&_HLS_part=2&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179958,93181159], cc [0, 0] duration:7196.851000000006
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181160 p: 1 cc: 0 of playlist [93179958-93181159] parts [0-25-25] level: 1, target: 7207.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7208.851
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181160 p: 1 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181160 part: 1 of track 0 [7192.863,7208.861]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1460 [log] > [stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181160 p: 1 of level 1
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [stream-controller]: Buffered main sn: 93181160 part: 1 of level 1 [7194.850,7208.850]
base-stream-controller.ts:1460 [log] > [stream-controller]: PARSED->IDLE
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [93179958-93181159]
base-playlist-controller.ts:127 [log] > [audio-track-controller]: live playlist 0 REFRESHED 93181160-2
audio-track-controller.ts:259 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
audio-stream-controller.ts:443 [log] > [audio-stream-controller]: Track 0 loaded [93179958,93181159],duration:7197.851000000006
base-stream-controller.ts:588 [log] > [audio-stream-controller]: Loading part sn: 93181160 p: 2 cc: 0 of playlist [93179958-93181159] parts [0-26-26] track: 0, target: 7208.861
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-playlist-controller.ts:127 [log] > [level-controller]: live playlist 1 REFRESHED 93181160-2
level-controller.ts:538 [log] > [level-controller]: Attempt loading level index 1 at sn 93181160 part 3 with URL-id 0 https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/index-s34-v.m3u8?_HLS_msn=93181160&_HLS_part=3&_HLS_skip=YES
stream-controller.ts:602 [log] > [stream-controller]: Level 1 loaded [93179958,93181159], cc [0, 0] duration:7197.851000000006
base-stream-controller.ts:588 [log] > [stream-controller]: Loading part sn: 93181160 p: 2 cc: 0 of playlist [93179958-93181159] parts [0-26-26] level: 1, target: 7208.85
base-stream-controller.ts:1460 [log] > [stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:648 [log] > [buffer-controller]: Updating Media Source duration to 7209.851
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
transmuxer-interface.ts:307 [log] > [transmuxer.ts]: Flushed fragment 93181160 p: 2 of level 0
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:493 [log] > [audio-stream-controller]: Buffered audio sn: 93181160 part: 2 of track 0 [7192.863,7209.860]
base-stream-controller.ts:1460 [log] > [audio-stream-controller]: PARSED->IDLE

Chrome media internals output

No response

robwalch · 2022-12-15T16:42:40Z

Setting currentLevel flushes all "main" media (video in this case). To do a smooth switch in Low-latency, set loadLevel only.

hls.ts:428 [log] > set currentLevel:1
hls.ts:469 [log] > set loadLevel:1

I noticed that on switch, buffering always begins from the first part of the next/last segment (depending on playhead). In the playlists, none of the parts signal whether they are independent or not. This could be why (or we have a bug).
Tested on v1.2.9 with the same config and could not reproduce. I used "Currently loaded level" (sets loadLevel) to switch:

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

at https://hls-js.netlify.app/demo/?src=https%3A%2F%2Fklive-stg.kaltura.com%2Fenv%2Fcluster-1-a.live.nvq1%2Flive%2Fhls%2Fp%2F5174%2Fe%2F0_rtdixfrs%2Ftl%2Fviewer%2Fst%2F0%2Fll%2F1%2Ft%2FWN9N1j2oRoBvtPzyLqDxVw%2Fmaster-s35-s34-s33-s42-s32-s43.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==

robwalch · 2022-12-16T00:34:14Z

There seems to be an issue with part loading order after loadLevel change:

The player selects mid-segment parts to switch on (assumes all parts are independent if not marked) which is what we want (overlapping part indexes are ok).

[stream-controller]: Buffered main sn: 93186052 part: 3 of level 2 [7669.847,7674.847][7675.847,7692.847][7705.847,7727.847]
[log] > set loadLevel:5
[log] > [stream-controller]: Level 5 loaded [93184850,93186051], cc [0, 0] duration:7200.847000000017
[stream-controller]: Loading part sn: 93186052 p: 3 cc: 0 of playlist [93184850-93186051] parts [0-27-28] level: 5, target: 7727.847

but then the part index resets to 0 after a level update

...
[level-controller]: live playlist 5 REFRESHED 93186052-5
[level-controller]: Attempt loading level index 5 at sn 93186053 part 0 with URL-id 0 https://.../index-s43-v.m3u8?_HLS_msn=93186053&_HLS_part=0&_HLS_skip=YES
[stream-controller]: Level 5 loaded [93184851,93186052], cc [0, 0] duration:7195.847000000018
[stream-controller]: Buffered main sn: 93186052 part: 4 of level 5 [7669.847,7674.847][7675.847,7692.847][7705.847,7728.847]
[stream-controller]: PARSED->IDLE
[stream-controller]: Loading part sn: 93186052 p: 0 cc: 0 of playlist [93184851-93186052] parts [0-18-23] level: 5, target: 7728.847

I would expect to see part 3 buffered, and the 4 and 5 loaded and buffered. I don't know how it got from loading 3, to buffering 4 to the selecting 0. Something must have gotten fudged on playlist refresh. Not sure if this is an issue with merging deltas and parts or a streaming controller state issue, but if it's not a stream issue it should be corrected in hls.js.

erankor · 2022-12-20T13:02:36Z

Thanks @robwalch!

Setting currentLevel flushes all "main" media (video in this case). To do a smooth switch in Low-latency, set loadLevel only.

You're right, that was my mistake in trying to reproduce the issue. In the original issue reported by our QA team, they didn't switch levels manually, they noticed it when the player initiated the level switch automatically.

I noticed that on switch, buffering always begins from the first part of the next/last segment (depending on playhead). In the playlists, none of the parts signal whether they are independent or not. This could be why (or we have a bug).

Not sure what you meant by "none of the parts signal whether they are independent or not", we are using the INDEPENDENT=YES attribute in our streams. In this case, the stream uses a GOP of 3 sec, so nearly always part indexes 0 & 3 in each video segment are marked as independent.

I ran some more tests, this time with 'Currently loaded level', and I'm still able to reproduce the stalls (even though it obviously behaves much better than 'Currently played level' :) ).

It it possible to reproduce also with the video-only version of this stream, by adding -v to the filename part of the URL - https://klive-stg.kaltura.com/env/cluster-1-a.live.nvq1/live/hls/p/5174/e/0_rtdixfrs/tl/viewer/st/0/ll/1/t/WN9N1j2oRoBvtPzyLqDxVw/master-s35-s34-s33-s42-s32-s43-v.m3u8
This removes some of the clutter in the network tab, and may help see what's going on...

In one of the tests I saw the following sequence of parts being loaded -
...
part-93241941-3-s35-v.m4s
part-93241941-4-s35-v.m4s
part-93241941-5-s35-v.m4s (cancelled)

part-93241941-4-s32-v.m4s
part-93241941-5-s32-v.m4s
part-93241941-1-s32-v.m4s
part-93241941-2-s32-v.m4s
part-93241941-3-s32-v.m4s
part-93241941-4-s32-v.m4s
part-93241941-5-s32-v.m4s
part-93241941-6-s32-v.m4s
part-93241942-1-s32-v.m4s
...
Our naming convention for parts is part-<segment index>-<part index>-s<rendition>-v.m4s. This means that the player initially tried to start from the part matching the last part that was loaded from the old level. But then it "changed its mind" and started from part index 0 of this segment. Maybe this can provide some clue on what happens here...

One last thing, I read the description of #5102, but with my current familiarity level of the code, it's all Greek to me :) do you think this PR can help here?

robwalch · 2022-12-20T19:28:49Z

One last thing, I read the description of #5102, but with my current familiarity level of the code, it's all Greek to me :) do you think this PR can help here?

I don't think it is relative to this issue.

What it will do is improve the accuracy of level reporting for the currentLevel getter and LEVEL_SWITCHED and FRAG_CHANGED events when seeking back to earlier parts of the playlist in streams like this (LL-HLS with long "DVR-like" playlists). Currently (in v1.2.x) when the player loads parts, it does not keep track of which parts were buffered where, in the same way that the player tracks which segments where buffered (for performance and to limit memory usage). With #5102 an approximate fragment is tracked for the parts buffered so that when seeking back, the currently playing quality (currentLevel) more or less reflects the parts appended rather than the current level at the edge.

robwalch · 2022-12-20T19:30:06Z

Not sure what you meant by "none of the parts signal whether they are independent or not", we are using the INDEPENDENT=YES attribute in our streams.

I did not see the INDEPENDENT=YES tags when first looking at the stream. That's what I was referring to. My mistake.

In this case, the stream uses a GOP of 3 sec, so nearly always part indexes 0 & 3 in each video segment are marked as independent.

With a part hold back and GOP of 3 seconds, while streaming parts, the player can only switch on INDEPENDENT parts. Selecting a load level is immediate and will not wait for such an opportunity. The same could probably be said about the ABR-controller. This creates a restrictive situation that the player has not been tuned for. Chances are that buffering for level switch will happen behind the playhead resulting in a visual "freeze", if not a stall until the next GOP. This should come down to the timing of the switch compared to the last requested/buffered fragment. Nothing we can do about manual selection there (even when setting load level) but perhaps the auto selection timing can be made a bit more sensitive to this kind of situation.

For starters though we should look at the fragment-part selection:

This means that the player initially tried to start from the part matching the last part that was loaded from the old level. But then it "changed its mind" and started from part index 0 of this segment.

Thanks. This is helpful. I would expect the player to always start on an independent part. Figuring out why it would begin a new level on anything other than part 0 or 3 in this case is the first step. This happens in getNextPart:

https://github.com/video-dev/hls.js/blob/v1.3.0-beta.2/src/controller/base-stream-controller.ts#L983

The next step will be figuring out why it "changed its mind". Looking at targetBufferTime will help (target: seconds in the logs). I would guess that the either:

buffered ranges changed - either we flushed some content or appended media without a key frame which removed part of the buffer.
part index resets to 0 only when index should be the last part of a segment or the last part in the playlist (or perhaps the next part)

… been loaded and next part is not listed Fixes #5111

robwalch · 2022-12-20T22:53:20Z

part index resets to 0

That was it. Fixed in #5122

I can still reproduce freezes of ~1-2 seconds with 3 second holdback, depending on whether a switch forces appends over the playhead. These freezes and stalls should be much less frequent now that the player isn't backtracking over the switch area.

There could still be a case where if parts 0-2 were loaded in rendition A then switch to rendition B but only parts 0-2 are listed, then part 0 will be picked instead of waiting for part 3 (same for parts 3-5). Seems unlikely with reports working.

robwalch · 2022-12-21T00:49:53Z

Freezing video when appends are made before currentTime is being tracked in #3596.

erankor · 2022-12-21T19:46:50Z

Thanks @robwalch!
We switched to 2 sec GOP, and tested with the latest changes - it seems to be working well, I haven't seen any freezes.
But I'm wondering... maybe it makes sense to delay the level switch until it can be performed without interruption?
I assume that if we increase the GOP size, let's say 6 sec, we'll get many freezes, and feels to me like it can be avoided...

robwalch · 2022-12-21T21:44:15Z

I assume that if we increase the GOP size, let's say 6 sec, we'll get many freezes, and feels to me like it can be avoided...

I'd like to continue to track that via #3596. Comments I made yesterday about the timing of auto switches (or when load level is changed relative to the availability of independent parts) here still apply.

… been loaded and next part is not listed (#5122) Fixes #5111

erankor added Bug Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Dec 15, 2022

robwalch added cannot reproduce and removed Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Dec 15, 2022

robwalch added Confirmed and removed cannot reproduce labels Dec 20, 2022

robwalch added this to HLS.js Release Planning and Backlog Dec 20, 2022

robwalch moved this to Top priorities in HLS.js Release Planning and Backlog Dec 20, 2022

robwalch added this to Low-Latency HLS (LL-HLS) Dec 20, 2022

robwalch moved this to To do in Low-Latency HLS (LL-HLS) Dec 20, 2022

robwalch added a commit that referenced this issue Dec 20, 2022

Fix nextPartIndex matching first independent part when later part has…

bae8867

… been loaded and next part is not listed Fixes #5111

robwalch mentioned this issue Dec 20, 2022

Fix Low-Latency HLS next part selection when switching mid segment #5122

Merged

3 tasks

robwalch removed this from HLS.js Release Planning and Backlog Dec 20, 2022

robwalch moved this from To do to In progress in Low-Latency HLS (LL-HLS) Dec 20, 2022

robwalch added this to the 1.3.0 milestone Dec 20, 2022

robwalch closed this as completed in #5122 Dec 21, 2022

robwalch added a commit that referenced this issue Dec 21, 2022

Fix nextPartIndex matching first independent part when later part has…

7e419d5

… been loaded and next part is not listed (#5122) Fixes #5111

robwalch moved this from In progress to Done in Low-Latency HLS (LL-HLS) Jan 11, 2023

adampfw mentioned this issue Jan 12, 2023

Chrome does not recognise old keyframes (LL-HLS issue) #3596

Open

5 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Video freezes on rendition switch in LLHLS #5111

Video freezes on rendition switch in LLHLS #5111

erankor commented Dec 15, 2022

robwalch commented Dec 15, 2022 •

edited

Loading

robwalch commented Dec 16, 2022 •

edited

Loading

erankor commented Dec 20, 2022

robwalch commented Dec 20, 2022

robwalch commented Dec 20, 2022 •

edited

Loading

robwalch commented Dec 20, 2022 •

edited

Loading

robwalch commented Dec 21, 2022

erankor commented Dec 21, 2022

robwalch commented Dec 21, 2022

Video freezes on rendition switch in LLHLS #5111

Video freezes on rendition switch in LLHLS #5111

Comments

erankor commented Dec 15, 2022

What version of Hls.js are you using?

What browser (including version) are you using?

What OS (including version) are you using?

Test stream

Configuration

Additional player setup steps

Checklist

Steps to reproduce

Expected behaviour

What actually happened?

Console output

Chrome media internals output

robwalch commented Dec 15, 2022 • edited Loading

robwalch commented Dec 16, 2022 • edited Loading

erankor commented Dec 20, 2022

robwalch commented Dec 20, 2022

robwalch commented Dec 20, 2022 • edited Loading

robwalch commented Dec 20, 2022 • edited Loading

robwalch commented Dec 21, 2022

erankor commented Dec 21, 2022

robwalch commented Dec 21, 2022

robwalch commented Dec 15, 2022 •

edited

Loading

robwalch commented Dec 16, 2022 •

edited

Loading

robwalch commented Dec 20, 2022 •

edited

Loading

robwalch commented Dec 20, 2022 •

edited

Loading