hls.js Audio fragments missing and incorrect start/end times

Audio fragments missing and incorrect start/end times

Open annatomka opened this issue 2 years ago • 1 comments

What version of Hls.js are you using?

1.2.0

What browser (including version) are you using?

Chrome 103.0.5060.134

What OS (including version) are you using?

macOS 11.6.7 Big Sur

Test stream

https://annatomka.github.io/hls.js/sample/playlist.m3u8

Configuration

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

Additional player setup steps

No response

Checklist

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

Steps to reproduce

Open demo page with sample playlist: https://hls-js-dev.netlify.app/demo/?src=https%3A%2F%2Fannatomka.github.io%2Fhls.js%2Fsample%2Fplaylist.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==
Play the video until the end

Expected behaviour

Video has only one gap (between 0:07 and 0:18), remaining part plays smoothly.

What actually happened?

A new audio gap is introduced (between 0:34 and 0:45), audio buffer looks like this: [0.005333, 7.962542] [17.989333, 34.991843] [44.975999, 59.802591] Hls.js 0.14.17 plays the remaining part smoothly, and has the following audio buffer: [0.005333, 7.962542] [17.989333, 59.802591]

Parsing the actual audio fragments, they have the following values: chunk_0_2a2daece6d.m4a: start: 5, duration: 7957, end: 7962 chunk_2_2a2daece6d.m4a: start: 17989, duration: 1962, end: 19951 chunk_3_2a2daece6d.m4a: start: 19951, duration: 5013, end: 24964 chunk_4_2a2daece6d.m4a: start: 24965, duration: 10026, end: 34991 chunk_5_2a2daece6d.m4a: start: 34991, duration: 4970, end: 39961 chunk_6_2a2daece6d.m4a: start: 39962, duration: 5013, end: 44975 chunk_7_2a2daece6d.m4a: start: 44975, duration: 5013, end: 49988 chunk_8_2a2daece6d.m4a: start: 49989, duration: 5013, end: 55002

It seems, that the new hls.js version does not parse the start values correctly.

In the older version (0.14.17) there was a startDTS calculation and the result was passed as a timeOffset to the remuxer for every fragment: https://github.com/video-dev/hls.js/blob/5275331ce1b8fb56a5f2032027650a2621a89ab0/src/demux/mp4demuxer.js#L392 and in the remuxer this timeout was set as startDTS: https://github.com/video-dev/hls.js/blob/5275331ce1b8fb56a5f2032027650a2621a89ab0/src/remux/passthrough-remuxer.js#L33 In audio-stream-controller the start and end times were updated based on the previous startDTS value: https://github.com/video-dev/hls.js/blob/5275331ce1b8fb56a5f2032027650a2621a89ab0/src/controller/audio-stream-controller.js#L596 Timeline using hls.js 0.14.17:

In the new version of hls.js the startDTS calculation is missing, and this results in invalid start and end times of the fragments as well as some of the audio fragments are not downloaded (sn 4 and sn 5). https://github.com/video-dev/hls.js/blob/297e5c90f4513b216ac80843582fb7106756eaca/src/remux/passthrough-remuxer.ts#L170 StartDTS is set to the previous endDTS value without parsing the actual startDTS value.

Timeline using hls.js 1.2.0:

Also, #EXTINF values of the audio playlist were considered in the previous version, e.g first chunk duration was calculated as 17.9839 and endDTS was 17.989333. Hls 1.2.0 seems to ignore playlist #EXTINF values.

I tried to put back the startDTS calculation in the passthrough remuxer: https://github.com/video-dev/hls.js/compare/master...annatomka:hls.js:audio-gap-fix The additional gap disappeared and also the start and end times look correct, but reaching the first gap the player won't skip it (manually seeking to a later timestamp e.g. 0:20 will help), here is the timeline with the change:

Here is the demo page with my modification: https://annatomka.github.io/hls.js/audio-gap-fix/?src=https%3A%2F%2Fannatomka.github.io%2Fhls.js%2Fsample%2Fplaylist.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==

Console output

Using Hls.js config: {debug: true, enableWorker: false, lowLatencyMode: false, backBufferLength: 90}
logger.ts:74 [log] >
hls.ts:371 [log] > stopLoad
hls.ts:339 [log] > loadSource:https://annatomka.github.io/hls.js/sample/playlist.m3u8
stream-controller.ts:546 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:310 [log] > attachMedia
level-controller.ts:172 [log] > [level-controller]: manifest loaded, 1 level(s) found, first bitrate: 861184
buffer-controller.ts:136 [log] > 2 bufferCodec event(s) expected
hls.ts:361 [log] > startLoad(-1)
level-controller.ts:251 [log] > [level-controller]: switching to level 0 from -1
audio-track-controller.ts:134 [log] > [audio-track-controller]: Updating audio tracks, 1 track(s) found in "audiogroup" group-id
audio-track-controller.ts:185 [log] > [audio-track-controller]: Now switching to audio-track index 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: STOPPED->IDLE
level-controller.ts:524 [log] > [level-controller]: Attempt loading level index 0 with URL-id 0 https://annatomka.github.io/hls.js/sample/video.m3u8
base-stream-controller.ts:1356 [log] > [stream-controller]: STOPPED->IDLE
audio-track-controller.ts:258 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->STOPPED
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: STOPPED->WAITING_TRACK
base-stream-controller.ts:1356 [log] > [subtitle-stream-controller]: STOPPED->IDLE
buffer-controller.ts:755 [log] > [buffer-controller]: Media source opened
stream-controller.ts:611 [log] > [stream-controller]: Level 0 loaded [0,7], cc [0, 0] duration:59.8
buffer-controller.ts:647 [log] > [buffer-controller]: Updating Media Source duration to 59.800
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment initSegment cc: 0 level: 0, target: 0
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [0-8]
audio-stream-controller.ts:446 [log] > [audio-stream-controller]: Track 0 loaded [0,8],duration:59.7946675
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: WAITING_TRACK->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment initSegment cc: 0 track: 0, target: 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: initSegment of level 0 
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-7] level: 0, target: 0
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->IDLE
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: initSegment of track 0 
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 0 cc: 0 of [0-8] track: 0, target: 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:191 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 0 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1249 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.4d001f/avc1.4d001f]
audio-stream-controller.ts:114 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 0
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 0 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 0 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 0 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 0
        initSegmentChange: true
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
audio-stream-controller.ts:839 [log] > [audio-stream-controller]: Switching audio track : flushing all audio
audio-stream-controller.ts:787 [log] > [audio-stream-controller]: Init audio buffer, container:audio/mp4, codecs[parsed]=[mp4a.40.2]
buffer-controller.ts:716 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.4d001f)
buffer-controller.ts:716 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2)
stream-controller.ts:818 [log] > [stream-controller]: Alternate track found, use video.buffered to schedule main fragment loading
buffer-controller.ts:829 [log] > [buffer-controller]: Removing [0,59.8] from the audio SourceBuffer
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 0 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 0 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 0 of level 0 [0.000,8.333]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 1 cc: 0 of [0-7] level: 0, target: 8.333
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 0 of track 0 [0.005,7.963]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 3 cc: 0 of [0-8] track: 0, target: 17.984
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
timeline-chart.ts:283 [Violation] 'requestAnimationFrame' handler took 63ms
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 1 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 3 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 14.9332089
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 3 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 3 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
timeline-chart.ts:262 [Violation] 'requestAnimationFrame' handler took 55ms
[Violation] Forced reflow while executing JavaScript took 46ms
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 3 of track 0 [0.005,7.963][24.965,34.992]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 1 cc: 0 of [0-8] track: 0, target: 7.963
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 1 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7.957209000000001
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 1 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 1 of track 0 [0.005,7.963][17.989,19.952][24.965,34.992]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1019 [log] > [audio-stream-controller]: SN 1 just loaded, load next one: 2
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 2 cc: 0 of [0-8] track: 0, target: 9.92
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 2 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 2 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 2 of track 0 [0.005,7.963][17.989,34.992]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 1 cc: 0 of [0-8] track: 0, target: 7.963
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 1 of level 0 [0.000,16.233]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 2 cc: 0 of [0-7] level: 0, target: 16.233
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 1 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 7.957209000000001
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 1 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 2 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 2 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 1 of track 0 [0.005,7.963][17.989,34.992]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 2 of level 0 [0.000,20.100]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 3 cc: 0 of [0-7] level: 0, target: 20.1
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 3 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 3 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 3 of level 0 [0.000,27.400]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 4 cc: 0 of [0-7] level: 0, target: 27.4
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 4 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 4 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 4 of level 0 [0.000,35.733]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 5 cc: 0 of [0-7] level: 0, target: 35.733
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 5 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 5 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 5 of level 0 [0.000,39.700]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 6 cc: 0 of [0-7] level: 0, target: 39.7
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 6 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 6 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 6 of level 0 [0.000,48.033]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [stream-controller]: Loading fragment 7 cc: 0 of [0-7] level: 0, target: 48.033
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [stream-controller]: Loaded fragment 7 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 7 of level 0
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [stream-controller]: Buffered main sn: 7 of level 0 [0.000,59.800]
base-stream-controller.ts:1356 [log] > [stream-controller]: PARSED->IDLE
buffer-controller.ts:520 [log] > [buffer-controller]: video sourceBuffer now EOS
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->ENDED
timeline-chart.ts:195 (2) [17.989333, 34.991843]
base-stream-controller.ts:217 [log] > [stream-controller]: media seeking to 18.407, state: ENDED
base-stream-controller.ts:1356 [log] > [stream-controller]: ENDED->IDLE
base-stream-controller.ts:217 [log] > [audio-stream-controller]: media seeking to 18.407, state: IDLE
base-stream-controller.ts:217 [log] > [subtitle-stream-controller]: media seeking to 18.407, state: IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 6 cc: 0 of [0-8] track: 0, target: 34.992
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
stream-controller.ts:537 [log] > [stream-controller]: Media seeked to 18.413
base-stream-controller.ts:1356 [log] > [stream-controller]: IDLE->ENDED
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 6 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 34.9437192
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 6 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 6 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 6 of track 0 [0.005,7.963][17.989,34.992][44.976,49.989]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1019 [log] > [audio-stream-controller]: SN 6 just loaded, load next one: 7
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 7 cc: 0 of [0-8] track: 0, target: 39.957
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 7 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 7 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 7 of track 0 [0.005,7.963][17.989,34.992][44.976,55.003]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 6 cc: 0 of [0-8] track: 0, target: 34.992
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 6 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 34.9437192
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 6 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 6 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 6 of track 0 [0.005,7.963][17.989,34.992][44.976,55.003]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1019 [log] > [audio-stream-controller]: SN 6 just loaded, load next one: 7
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 7 cc: 0 of [0-8] track: 0, target: 39.957
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 7 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 7 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 7 of track 0 [0.005,7.963][17.989,34.992][44.976,55.003]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 6 cc: 0 of [0-8] track: 0, target: 34.992
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:191 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 6 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 34.9437192
        initSegmentChange: false
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:362 [log] > [audio-stream-controller]: Loaded fragment 6 of level 0
transmuxer.ts:257 [log] > [transmuxer.ts]: Flushed fragment 6 of level 0
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:492 [log] > [audio-stream-controller]: Buffered audio sn: 6 of track 0 [0.005,7.963][17.989,34.992][44.976,55.003]
base-stream-controller.ts:1356 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:1019 [log] > [audio-stream-controller]: SN 6 just loaded, load next one: 7
base-stream-controller.ts:581 [log] > [audio-stream-controller]: Loading fragment 7 cc: 0 of [0-8] track: 0, target: 39.957

Chrome media internals output

No response

Aug 04 '22 18:08 annatomka

Hi @annatomka,

I tried to put back the startDTS calculation in the passthrough remuxer: https://github.com/video-dev/hls.js/compare/master...annatomka:hls.js:audio-gap-fix

Thanks for narrowing down the issue to this change.

My guess is that the intention was to collapse segments together to prevent gaps. However when muxing with video we should honor the media timecode to keep things in sync. This is a good fix, but based on the mp4-remuxer aligns audio and video tracks, but allows collapsing of audio only, I am inclined to say that we should only apply this change when remuxing audio and video (as with your sample stream). I don't know if the passthrough-remuxer has anything it can use to signal whether or not that is the case. It might also make sense to log a warning when lastEndDTS and getStartDTS differ significantly (as we do in here https://github.com/video-dev/hls.js/blob/master/src/remux/mp4-remuxer.ts#L775 (ignore that we also inject frames)).

reaching the first gap the player won't skip it

Gap traversal is another issue. Typically this much missing media would call for a GAP tag (we still don't support this) which may result in the entire segment being skipped if no alternate could be found in the manifest. Our gap jumping is configurable but usually you don't want to allow such large gaps. I would suggest adding your own seek behavior or fixing the stream if this is common.

Aug 04 '22 19:08 robwalch

Upon further investigation this issue has less to do with startDTS calculation and everything to do with the playlist segment durations being incorrect which is throwing off nextLoadPosition in HLS.js's audio-stream-controller. Because the first segment is listed as 17 seconds in length, but is closer to 8, after loading the first audio segment, it looks for the next segment at 17 seconds which finds the fourth segment (skipping loading of the second and third audio segments).

Even if we were to correct the stream controller to load the second and third segment, they don't start until 17 seconds in the program. The first audio segment has a 9 second gap. The playlist should include GAP tag to cover indicate this, but regardless there is no action HLS.js can take at this time for such large gaps whether or not they are labelled in the playlist.

Aug 27 '22 00:08 robwalch

Hi, Thank you for the fix :)

Aug 30 '22 09:08 annatomka

hls.js hls.js copied to clipboard

Audio fragments missing and incorrect start/end times

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

hls.js
hls.js copied to clipboard