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

BufferAppendError in Chrome when loading HLG segments and no fallback to SDR

Open knuthaug opened this issue 5 months ago • 1 comments

What version of Hls.js are you using?

1.6.12

What browser (including version) are you using?

Chrome Version 140.0.7339.133 (Official Build) (arm64)

What OS (including version) are you using?

macos Seqouia 15.6.1 (24G90)

Test stream

https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Fnrk-od-world-53.akamaized.net%2Fopen%2Fps%2Fmuhu%2Fmuhu16000124%2F4e8fcc18-43.smil%2Fcmaf.m3u8%3Fadap%3Dlarge_h265&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==

Alternative test stream in case the above url changes/is no longer available: https://nrk-od2.telenorcdn.net/open/ps/ttvl/ttvl10000023/42f69a22-18.smil/cmaf.m3u8?adap=large_h265

Configuration

{
  "debug": true,
  "enableWorker": true,
  "lowLatencyMode": true,
  "backBufferLength": 90,
  "videoPreference": {
    "preferHDR": true,
    "allowedVideoRanges": [
 "HLG",
 "SDR"
    ]
  }
}

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://hlsjs.video-dev.org/demo and not just on my page
  • [x] The issue occurs in the latest client (main branch) on https://hlsjs-dev.video-dev.org/demo and not just on my page
  • [x] The stream has correct Access-Control-Allow-Origin headers (CORS)
  • [x] There are no network errors such as 404s in the browser console when trying to play the stream

Steps to reproduce

  1. Open the demo page on a device with a screen capable of HDR colors (e.g a macbook) in chrome.
  2. Use config and stream url provided above, to enable HDR playback
  3. start stream

Expected behaviour

First of all, the provided example streams plays well on the test machine in Safari with native HLS, in firefox with hls.js demo player and also on other HDR capable devices such as AppleTV and Android devices.

I would expect primarily that HDR playback works, secondly if that fails hls.js should fallback to SDR playback.

What actually happened?

On Chrome, hls.js tries to select HDR qualities but fails with bufferAppendErrors repeating endlessly. It does not recover and fall back to SDR levels. As mentioned this does not happen in Firefox on the same machine, so my theory is buffer handling in chrome is not handling the data as it should. The same behaviour is seen in shaka player in chrome too. I'm not entirely clear on what part of video buffering is handled by the browser versus handled by hls.js.

So this is maybe a chrome bug, but I also feel that hls.js could handle the error better. As it is today it fails to start the stream completely and thus we cannot enable HDR chrome-based browser even though the browser reports high dynamic range support. Which is a shame :-/

Console output

Using Hls.js config: {debug: true, enableWorker: true, lowLatencyMode: true, backBufferLength: 30, videoPreference: {…}}
logger.ts:102 [log] > Debug logs enabled for "Hls instance" in hls.js version 1.6.12
hls.ts:579 [log] > stopLoad
hls.ts:513 [log] > loadSource:https://nrk-od-world-53.akamaized.net/open/ps/muhu/muhu16000124/4e8fcc18-43.smil/cmaf.m3u8?adap=large_h265
interstitials-controller.ts:288 [log] > [interstitials]: clear schedule state
stream-controller.ts:601 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:466 [log] > attachMedia
buffer-controller.ts:320 [log] > [buffer-controller]: created media source: MediaSource
level-controller.ts:351 [log] > [level-controller]: manifest loaded, 7 level(s) found, first bitrate: 15857635
abr-controller.ts:65 [log] > [abr]: setting initial bwe to 5000000
buffer-controller.ts:266 [log] > [buffer-controller]: 2 bufferCodec event(s) expected.
abr-controller.ts:802 [log] > [abr]: picked start tier {"codecSet":"hvc1,mp4a","videoRanges":["HLG"],"preferHDR":true,"minFramerate":25,"minBitrate":1612255,"minIndex":1}
abr-controller.ts:978 [info] > [abr]: switch candidate:6->3 adjustedbw(5000000)-bitrate=1509666 ttfb:0.1 avgDuration:0.0 maxFetchDuration:4.0 fetchDuration:0.2 firstSelection:true codecSet:hvc1,mp4a videoRange:HLG hls.loadLevel:-1
playlist-loader.ts:397 [log] > auto startLoad with configured startPosition -1
hls.ts:556 [log] > startLoad(-1)
level-controller.ts:450 [log] > [level-controller]: Switching to level 3 (720p HLG hvc1,mp4a @3490334) from level -1
audio-track-controller.ts:187 [log] > [audio-track-controller]: Updating audio tracks, 1 track(s) found in group(s): aud3
audio-track-controller.ts:326 [log] > [audio-track-controller]: Switching to audio-track 0 "Unknown" lang:un group:aud3 channels:2
base-stream-controller.ts:2054 [log] > [audio-stream-controller]: Reset loading state
subtitle-track-controller.ts:285 [log] > [subtitle-track-controller]: Updating subtitle tracks, 2 track(s) found in "sub1" group-id
level-controller.ts:655 [log] > [level-controller]: Loading level index 3 https://nrk-od-world-53.akamaized.net/open/ps/muhu/muhu16000124/4e8fcc18-43.smil/sc-gaFEQg/V7_index.m3u8?adap=large_h265
base-stream-controller.ts:2230 [log] > [stream-controller]: STOPPED->IDLE
audio-track-controller.ts:421 [log] > [audio-track-controller]: Loading audio-track 0 "Unknown" lang:un group:aud3 https://nrk-od-world-53.akamaized.net/open/ps/muhu/muhu16000124/4e8fcc18-43.smil/sc-gaFEQg/A2_index.m3u8?adap=large_h265
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: STOPPED->WAITING_TRACK
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: STOPPED->IDLE
buffer-controller.ts:1546 [log] > [buffer-controller]: Media source opened
subtitle-track-controller.ts:538 [log] > [subtitle-track-controller]: Switching to subtitle-track 0 "Norsk" lang:no group:sub1
subtitle-track-controller.ts:448 [log] > [subtitle-track-controller]: Loading subtitle 0 "Norsk" lang:no group:sub1 https://nrk-od-world-53.akamaized.net/open/ps/muhu/muhu16000124/4e8fcc18-43.smil/sc-gaFEQg/s0_index.m3u8?adap=large_h265
buffer-controller.ts:1375 [log] > [buffer-controller]: checkPendingTracks (pending: 0 codec events expected: 2) {}
stream-controller.ts:661 [log] > [stream-controller]: Level 3 loaded [0,363][part-363--1], cc [0, 0] duration:1746.9599999999891
base-stream-controller.ts:1823 [log] > [stream-controller]: setting startPosition to 0 by default
interstitials-controller.ts:1036 [log] > [interstitials]: [checkStart] Advancing timeline position to 0
interstitials-controller.ts:1135 [log] > [interstitials]: setSchedulePosition 0, undefined ([primary: 0.00-1746.96]) pos: 0
interstitials-controller.ts:2005 [log] > [interstitials]: INTERSTITIALS_BUFFERED_TO_BOUNDARY [primary: 0.00-1746.96]
interstitials-controller.ts:1397 [log] > [interstitials]: resuming [primary: 0.00-1746.96]
interstitials-controller.ts:1487 [log] > [interstitials]: [attachPrimary] Advancing timeline position to 0
buffer-controller.ts:1352 [log] > [buffer-controller]: Updating MediaSource duration to 1746.960
base-stream-controller.ts:965 [log] > [stream-controller]: Loading main sn: initSegment of level 3 (frag:[0.000-0.000]) cc: 0 [0-363], target: 0
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->FRAG_LOADING
audio-track-controller.ts:101 [log] > [audio-track-controller]: Audio track 0 "Unknown" lang:un group:aud3 loaded [0-363]
audio-stream-controller.ts:548 [log] > [audio-stream-controller]: Audio track 0 "Unknown" of "aud3" loaded [0,363][part-363--1],duration:1746.986669999989
base-stream-controller.ts:1823 [log] > [audio-stream-controller]: setting startPosition to 0 by default
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: WAITING_TRACK->IDLE
base-stream-controller.ts:965 [log] > [audio-stream-controller]: Loading audio sn: initSegment of track 0 (frag:[0.000-0.000]) cc: 0 [0-363], target: 0
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
subtitle-track-controller.ts:197 [log] > [subtitle-track-controller]: Subtitle track 0 "Norsk" lang:no group:sub1 loaded [0-29]
subtitle-stream-controller.ts:288 [log] > [subtitle-stream-controller]: Subtitle track 0 loaded [0,29][part-29--1],duration:1800
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 0 of track 0 (frag:[0.000-60.000]) cc: 0 [0-29], target: 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:2230 [log] > [stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:965 [log] > [stream-controller]: Loading main sn: 0 of level 3 (frag:[0.000-4.800]) cc: 0 [0-363], target: 0
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:965 [log] > [audio-stream-controller]: Loading audio sn: 0 of track 0 (frag:[0.000-4.800]) cc: 0 [0-363], target: 0
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 0 of track 0
transmuxer-interface.ts:88 [log] > injecting Web Worker for "audio"
audio-stream-controller.ts:675 [log] > [audio-stream-controller]: Unknown video PTS for cc 0, waiting for video PTS before demuxing audio frag 0 of [0 ,363],track 0
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: FRAG_LOADING->WAITING_INIT_PTS
base-stream-controller.ts:537 [log] > [audio-stream-controller]: Loaded audio sn: 0 of track 0
transmuxer-interface.ts:88 [log] > injecting Web Worker for "main"
transmuxer-interface.ts:238 [log] > [transmuxer-interface]: Starting new transmux session for main sn: 0 level: 3 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:537 [log] > [stream-controller]: Loaded main sn: 0 of level 3
57016bb5-455a-4faa-adf1-92003d355b26:1168 [log] > Debug logs enabled for "audio" in hls.js version 1.6.12
57016bb5-455a-4faa-adf1-92003d355b26:1168 [log] > Debug logs enabled for "main" in hls.js version 1.6.12
transmuxer-interface.ts:396 [log] > [passthrough-remuxer]: Found initPTS at playlist time: 0 offset: 0 (0/12800) trackId: 1
base-stream-controller.ts:2230 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1519 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[hvc1.2.4.L93.90/hev1.2.4.L93.90]
buffer-controller.ts:594 [log] > [buffer-controller]: BUFFER_CODECS: "video" (current SB count 0)
buffer-controller.ts:1375 [log] > [buffer-controller]: checkPendingTracks (pending: 1 codec events expected: 2) {"video":{"listeners":[],"codec":"hev1.2.4.L93.90","container":"video/mp4","levelCodec":"hvc1.2.4.L93.90","id":"main"}}
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: initSegment of level 3 cc: 0
audio-stream-controller.ts:153 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 0 (0/12800) trackId: 1
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 0 of track 0 (frag:[0.000-60.000] > buffer:[0.000-60.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 1 of track 0 (frag:[60.000-120.000]) cc: 0 [0-29], target: 60
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "video" append sn: 0 of level 3 cc: 0
transmuxer-interface.ts:396 [log] > [transmuxer.ts]: Flushed main sn: 0 of level 3
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:2177 [log] > [stream-controller]: Parsed main sn: 0 of level 3 (frag:[0.000-4.800])
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 1 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 1 of track 0 (frag:[60.000-120.000] > buffer:[0.000-120.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 2 of track 0 (frag:[120.000-180.000]) cc: 0 [0-29], target: 120
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 2 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 2 of track 0 (frag:[120.000-180.000] > buffer:[0.000-180.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 3 of track 0 (frag:[180.000-240.000]) cc: 0 [0-29], target: 180
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 3 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 3 of track 0 (frag:[180.000-240.000] > buffer:[0.000-240.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 4 of track 0 (frag:[240.000-300.000]) cc: 0 [0-29], target: 240
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 4 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 4 of track 0 (frag:[240.000-300.000] > buffer:[0.000-300.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 5 of track 0 (frag:[300.000-360.000]) cc: 0 [0-29], target: 300
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 5 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 5 of track 0 (frag:[300.000-360.000] > buffer:[0.000-360.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 6 of track 0 (frag:[360.000-420.000]) cc: 0 [0-29], target: 360
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 6 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 6 of track 0 (frag:[360.000-420.000] > buffer:[0.000-420.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 7 of track 0 (frag:[420.000-480.000]) cc: 0 [0-29], target: 420
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 7 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 7 of track 0 (frag:[420.000-480.000] > buffer:[0.000-480.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 8 of track 0 (frag:[480.000-540.000]) cc: 0 [0-29], target: 480
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 8 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 8 of track 0 (frag:[480.000-540.000] > buffer:[0.000-540.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 9 of track 0 (frag:[540.000-600.000]) cc: 0 [0-29], target: 540
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 9 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 9 of track 0 (frag:[540.000-600.000] > buffer:[0.000-600.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 10 of track 0 (frag:[600.000-660.000]) cc: 0 [0-29], target: 600
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 10 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 10 of track 0 (frag:[600.000-660.000] > buffer:[0.000-660.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 11 of track 0 (frag:[660.000-720.000]) cc: 0 [0-29], target: 660
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 11 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 11 of track 0 (frag:[660.000-720.000] > buffer:[0.000-720.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 12 of track 0 (frag:[720.000-780.000]) cc: 0 [0-29], target: 720
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 12 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 12 of track 0 (frag:[720.000-780.000] > buffer:[0.000-780.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 13 of track 0 (frag:[780.000-840.000]) cc: 0 [0-29], target: 780
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 13 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 13 of track 0 (frag:[780.000-840.000] > buffer:[0.000-840.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 14 of track 0 (frag:[840.000-900.000]) cc: 0 [0-29], target: 840
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 14 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 14 of track 0 (frag:[840.000-900.000] > buffer:[0.000-900.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 15 of track 0 (frag:[900.000-960.000]) cc: 0 [0-29], target: 900
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 15 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 15 of track 0 (frag:[900.000-960.000] > buffer:[0.000-960.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 16 of track 0 (frag:[960.000-1020.000]) cc: 0 [0-29], target: 960
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 16 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 16 of track 0 (frag:[960.000-1020.000] > buffer:[0.000-1020.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 17 of track 0 (frag:[1020.000-1080.000]) cc: 0 [0-29], target: 1020
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: WAITING_INIT_PTS->FRAG_LOADING
transmuxer-interface.ts:238 [log] > [transmuxer-interface]: Starting new transmux session for audio sn: 0 track: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
audio-stream-controller.ts:965 [log] > [audio-stream-controller]: Init audio buffer, container:audio/mp4, codecs[level/parsed]=[mp4a.40.2/mp4a.40.2]
buffer-controller.ts:594 [log] > [buffer-controller]: BUFFER_CODECS: "audio" (current SB count 0)
buffer-controller.ts:1375 [log] > [buffer-controller]: checkPendingTracks (pending: 2 codec events expected: 2) {"video":{"listeners":[],"codec":"hev1.2.4.L93.90","container":"video/mp4","levelCodec":"hvc1.2.4.L93.90","id":"main"},"audio":{"listeners":[],"codec":"mp4a.40.2","container":"audio/mp4","levelCodec":"mp4a.40.2","id":"audio"}}
buffer-controller.ts:1444 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=hev1.2.4.L93.90) Queued {"listeners":[],"codec":"hev1.2.4.L93.90","container":"video/mp4","levelCodec":"hvc1.2.4.L93.90","id":"main"}
buffer-controller.ts:1444 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2) {"listeners":[],"codec":"mp4a.40.2","container":"audio/mp4","levelCodec":"mp4a.40.2","id":"audio"}
stream-controller.ts:964 [log] > [stream-controller]: Alternate track found, use video.buffered to schedule main fragment loading
buffer-controller.ts:1413 [log] > [buffer-controller]: SourceBuffers created. Running queue: 
video: (SourceBuffer) append-video, append-video, async-blocker
audio: (SourceBuffer) 
audiovideo: (none) }
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: initSegment of track 0 cc: 0
buffer-controller.ts:952 [log] > [buffer-controller]: queuing "audio" append sn: 0 of track 0 cc: 0
transmuxer-interface.ts:396 [log] > [transmuxer.ts]: Flushed audio sn: 0 of track 0
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:2177 [log] > [audio-stream-controller]: Parsed audio sn: 0 of track 0 (frag:[0.000-4.800])
base-stream-controller.ts:537 [log] > [subtitle-stream-controller]: Loaded subtitle sn: 17 of track 0
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:768 [log] > [subtitle-stream-controller]: Buffered subtitle sn: 17 of track 0 (frag:[1020.000-1080.000] > buffer:[0.000-1080.000])
base-stream-controller.ts:965 [log] > [subtitle-stream-controller]: Loading subtitle sn: 18 of track 0 (frag:[1080.000-1140.000]) cc: 0 [0-29], target: 1080
base-stream-controller.ts:2230 [log] > [subtitle-stream-controller]: IDLE->FRAG_LOADING
buffer-controller.ts:1612 [error] > [buffer-controller]: Error: video SourceBuffer error. MediaSource readyState: ended Event {isTrusted: true, type: 'error', target: SourceBuffer, currentTarget: SourceBuffer, eventPhase: 2, …}
onSBUpdateError @ buffer-controller.ts:1612Understand this error
main.js:745 Error event: {type: 'mediaError', details: 'bufferAppendingError', sourceBufferName: 'video', error: Error: video SourceBuffer error. MediaSource readyState: ended
    at BufferController.onSBUpdateEr…, fatal: false, …}details: "bufferAppendingError"error: Error: video SourceBuffer error. MediaSource readyState: ended
    at BufferController.onSBUpdateError (https://hlsjs.video-dev.org/dist/hls.js:20219:19)message: "video SourceBuffer error. MediaSource readyState: ended"stack: "Error: video SourceBuffer error. MediaSource readyState: ended\n    at BufferController.onSBUpdateError (https://hlsjs.video-dev.org/dist/hls.js:20219:19)"[[Prototype]]: ObjecterrorAction: {action: 0, flags: 0}fatal: falsesourceBufferName: "video"type: "mediaError"[[Prototype]]: Object
(anonymous) @ main.js:745
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
onSBUpdateError @ buffer-controller.ts:1615Understand this warning
buffer-controller.ts:939 [warn] > [buffer-controller]: Failed 1/3 times to append segment in "video" sourceBuffer (no media error)
onError @ buffer-controller.ts:939
onSBUpdateError @ buffer-controller.ts:1625Understand this warning
base-stream-controller.ts:2003 [warn] > [stream-controller]: Buffer full error while media.currentTime (4.8) is not buffered, flush main buffer
reduceLengthAndFlushBuffer @ base-stream-controller.ts:2003
onError @ stream-controller.ts:1049
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
onError @ buffer-controller.ts:949
onSBUpdateError @ buffer-controller.ts:1625Understand this warning
base-stream-controller.ts:2054 [log] > [stream-controller]: Reset loading state
base-stream-controller.ts:2230 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:2054 [log] > [stream-controller]: Reset loading state
error-controller.ts:479 [warn] > [error-controller]: MediaSource ended after "video" sourceBuffer append error. Attempting to recover from media error.
onErrorOut @ error-controller.ts:479
emit @ index.js:203
emit @ hls.ts:386
trigger @ hls.ts:394
onError @ buffer-controller.ts:949
onSBUpdateError @ buffer-controller.ts:1625Understand this warning
hls.ts:662 [log] > recoverMediaError
hls.ts:482 [log] > detachMedia
buffer-controller.ts:466 [log] > [buffer-controller]: media source detaching
base-stream-controller.ts:2230 [log] > [stream-controller]: IDLE->STOPPED
base-stream-controller.ts:2230 [log] > [audio-stream-controller]: PARSED->STOPPED

Chrome media internals output

{
  "7:1514": {
    "id": "7:1514",
    "properties": {
      "render_id": 7,
      "player_id": 1514,
      "created": "2025-09-11 07:01:36.811912 UTC",
      "origin_url": "https://hlsjs.video-dev.org/",
      "kFrameUrl": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Fnrk-od-world-53.akamaized.net%2Fopen%2Fps%2Fmuhu%2Fmuhu16000124%2F4e8fcc18-43.smil%2Fcmaf.m3u8%3Fadap%3Dlarge_h265&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==",
      "kFrameTitle": "hls.js demo",
      "url": "blob:https://hlsjs.video-dev.org/6e47c495-daa8-4566-a7fe-e331216f7672",
      "info": "ChunkDemuxer",
      "kRendererName": "RendererImpl",
      "pipeline_state": "kStopped",
      "error": "RunSegmentParserLoop: stream parsing failed. append_window_start=0 append_window_end=inf",
      "event": "kWebMediaPlayerDestroyed",
      "duration": 1746.959999
    },
    "allEvents": [
      {
        "time": 0,
        "key": "created",
        "value": "2025-09-11 07:01:36.811912 UTC"
      },
      {
        "time": 0.04799997806549072,
        "key": "origin_url",
        "value": "https://hlsjs.video-dev.org/"
      },
      {
        "time": 0.050999999046325684,
        "key": "kFrameUrl",
        "value": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Fnrk-od-world-53.akamaized.net%2Fopen%2Fps%2Fmuhu%2Fmuhu16000124%2F4e8fcc18-43.smil%2Fcmaf.m3u8%3Fadap%3Dlarge_h265&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ=="
      },
      {
        "time": 0.05299997329711914,
        "key": "kFrameTitle",
        "value": "hls.js demo"
      },
      {
        "time": 0.08799999952316284,
        "key": "url",
        "value": "blob:https://hlsjs.video-dev.org/6e47c495-daa8-4566-a7fe-e331216f7672"
      },
      {
        "time": 0.10100001096725464,
        "key": "info",
        "value": "ChunkDemuxer"
      },
      {
        "time": 0.10699999332427979,
        "key": "kRendererName",
        "value": "RendererImpl"
      },
      {
        "time": 0.11500000953674316,
        "key": "pipeline_state",
        "value": "kStarting"
      },
      {
        "time": 210.81999999284744,
        "key": "error",
        "value": "RunSegmentParserLoop: stream parsing failed. append_window_start=0 append_window_end=inf"
      },
      {
        "time": 212.6389999985695,
        "key": "pipeline_state",
        "value": "kStopping"
      },
      {
        "time": 212.64200001955032,
        "key": "pipeline_state",
        "value": "kStopped"
      },
      {
        "time": 212.64200001955032,
        "key": "event",
        "value": "kWebMediaPlayerDestroyed"
      },
      {
        "time": 0.23799997568130493,
        "key": "duration",
        "value": 1746.959999
      }
    ],
    "lastRendered": 0,
    "firstTimestamp_": 454792404.893,
    "playerState": "errored"
  },
  "7:1515": {
    "id": "7:1515",
    "properties": {
      "render_id": 7,
      "player_id": 1515,
      "created": "2025-09-11 07:01:37.028236 UTC",
      "origin_url": "https://hlsjs.video-dev.org/",
      "kFrameUrl": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Fnrk-od-world-53.akamaized.net%2Fopen%2Fps%2Fmuhu%2Fmuhu16000124%2F4e8fcc18-43.smil%2Fcmaf.m3u8%3Fadap%3Dlarge_h265&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==",
      "kFrameTitle": "hls.js demo",
      "url": "blob:https://hlsjs.video-dev.org/804b8fb7-9ed0-428b-aad9-bb768a0a791a",
      "info": "ChunkDemuxer",
      "kRendererName": "RendererImpl",
      "pipeline_state": "kStopped",
      "error": "RunSegmentParserLoop: stream parsing failed. append_window_start=0 append_window_end=inf",
      "event": "kWebMediaPlayerDestroyed",
      "duration": 1746.959999
    },
    "allEvents": [
      {
        "time": 0,
        "key": "created",
        "value": "2025-09-11 07:01:37.028236 UTC"
      },
      {
        "time": 0.053000032901763916,
        "key": "origin_url",
        "value": "https://hlsjs.video-dev.org/"
      },
      {
        "time": 0.0559999942779541,
        "key": "kFrameUrl",
        "value": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Fnrk-od-world-53.akamaized.net%2Fopen%2Fps%2Fmuhu%2Fmuhu16000124%2F4e8fcc18-43.smil%2Fcmaf.m3u8%3Fadap%3Dlarge_h265&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ=="
      },
      {
        "time": 0.058000028133392334,
        "key": "kFrameTitle",
        "value": "hls.js demo"
      },
      {
        "time": 0.0910000205039978,
        "key": "url",
        "value": "blob:https://hlsjs.video-dev.org/804b8fb7-9ed0-428b-aad9-bb768a0a791a"
      },
      {
        "time": 0.1040000319480896,
        "key": "info",
        "value": "ChunkDemuxer"
      },
      {
        "time": 0.11000001430511475,
        "key": "kRendererName",
        "value": "RendererImpl"
      },
      {
        "time": 0.12000000476837158,
        "key": "pipeline_state",
        "value": "kStarting"
      },
      {
        "time": 209.79900002479553,
        "key": "error",
        "value": "RunSegmentParserLoop: stream parsing failed. append_window_start=0 append_window_end=inf"
      },
      {
        "time": 211.6110000014305,
        "key": "pipeline_state",
        "value": "kStopping"
      },
      {
        "time": 211.61300003528595,
        "key": "event",
        "value": "kWebMediaPlayerDestroyed"
      },
      {
        "time": 211.61400002241135,
        "key": "pipeline_state",
        "value": "kStopped"
      },
      {
        "time": 0.24700003862380981,
        "key": "duration",
        "value": 1746.959999
      }
    ],
    "lastRendered": 0,
    "firstTimestamp_": 454792621.223,
    "playerState": "errored"
  },
 
 ... cut due to length and duplication

knuthaug avatar Sep 11 '25 07:09 knuthaug

It looks like there is a problem in the error-controller: getLevelSwitchAction recognizes that this is a video source buffer error and that it should find a codec alternate, but it does not find any. I'd expect that it finds and switches to the AVC variants, and recovers after it calls recoverMediaError.

https://github.com/video-dev/hls.js/blob/903f463311c6487a9e21b9a7c9ef059cc7593772/src/controller/error-controller.ts#L380-L393

Instead, error handling falls back to append retries. That should give up with a fatal error after config.appendErrorMaxRetry attempts. I haven't gotten as fas as to see if that is the case or if the count is reset somewhere.

robwalch avatar Sep 11 '25 19:09 robwalch