Playback starts from 3 seconds only in compiled form (vite) #5617

JWo1F · 2023-07-03T16:23:13Z

What version of Hls.js are you using?

1.4.0 — 1.4.7

What browser (including version) are you using?

Chrome 114.0.5735.198 (Official Build) (arm64)

What OS (including version) are you using?

Mac OS Ventura

Test stream

https://slingshot-assets-development.s3.us-east-2.amazonaws.com/video/a3bdbb85-ffb1-4f3b-9f99-34dfa1a0e869/HLS/258e7546b35fd10d6550ce45204207c6_1080.m3u8

Configuration

{ enableWorker: true, progressive: true, debug: true }

Additional player setup steps

No response

Checklist

The issue observed is not already reported by searching on Github under https:/video-dev/hls.js/issues
The issue occurs in the stable client (latest release) on https://hlsjs.video-dev.org/demo and not just on my page
The issue occurs in the latest client (main branch) on https://hlsjs-dev.video-dev.org/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

Install Vite + React (last version)
Insert hls.js code
Bundle and minify the code
Start playlist

Expected behaviour

Playback starts from 0 second.

What actually happened?

Playback starts from 3 second.

Console output

[warn] > skipping hole, adjusting currentTime from 0 to 3.5425

Chrome media internals output

No response

JWo1F · 2023-07-03T16:24:43Z

The bug does not reproduce on versions <= 1.3.5, also the bug does not reproduce when running a dev version (without minification). The bug does not reproduce on another video.

robwalch · 2023-07-03T16:45:30Z

progressive: true

Is the issue only reproducible with this setting on? It's listed as experimental in the docs.

JWo1F · 2023-07-03T17:16:28Z

Nope, without progressive: true the issue is reproducible too.

JWo1F · 2023-07-03T17:34:27Z

I've prepared a github repo with minimal reproducible code:
https:/JWo1F/hls-start-from-3

You can try it by yourself:

Scenario 1 (working):

Clone repository
Run npm run dev
Open localhost

Scenario 2 (the bug):

Clone repository
Run npm run build
Run serve dist or other http server for dist folder
Open localhost
Playback starts from 3 second

robwalch · 2023-07-03T18:09:10Z

Can you attach full debug logs to the issue. This should include segment loading, demuxing, and buffer append details that should provide some insight into why the gap controller seeks over such a large gap on start.

JWo1F · 2023-07-03T18:16:16Z

Sure:

[log] > Debug logs enabled for "Hls instance" in hls.js version 1.4.7
[log] > attachMedia
[log] > [buffer-controller]: Media source opened
[log] > [subtitle-stream-controller]: STOPPED->IDLE
[log] > stopLoad
[log] > [subtitle-stream-controller]: IDLE->STOPPED
[log] > loadSource:http://localhost:3000/main.m3u8
[log] > [stream-controller]: Trigger BUFFER_RESET
[log] > [level-controller]: manifest loaded, 1 level(s) found, first bitrate: 0
[log] > 1 bufferCodec event(s) expected
[log] > startLoad(-1)
[log] > [level-controller]: Switching to level 0 from level -1
[log] > [stream-controller]: STOPPED->IDLE
[log] > [subtitle-stream-controller]: STOPPED->IDLE
[log] > [stream-controller]: Level 0 loaded [1,3][part-3--1], cc [0, 0] duration:29
[log] > [buffer-controller]: Updating Media Source duration to 29.000
[log] > [stream-controller]: Loading fragment 1 cc: 0 of [1-3] level: 0, target: 0
[log] > [stream-controller]: IDLE->FRAG_LOADING
[log] > injecting Web Worker for "main"
[log] > [transmuxer-interface, main]: Starting new transmux session for sn: 1 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: true
[log] > [stream-controller]: Loaded fragment 1 of level 0
[warn] > Error in "main" Web Worker, fallback to inline
R.onerror @ index-e43ca4bb.js:41
[log] > [stream-controller]: Reset loading state
[log] > [stream-controller]: FRAG_LOADING->IDLE
[log] > [audio-stream-controller]: Reset loading state
[log] > [audio-stream-controller]: STOPPED->IDLE
[log] > [stream-controller]: Loading fragment 2 cc: 0 of [1-3] level: 0, target: 11
[log] > [stream-controller]: IDLE->FRAG_LOADING
[log] > [transmuxer-interface, main]: Starting new transmux session for sn: 2 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 11
        initSegmentChange: true
[log] > [mp4-remuxer]: ISGenerated flag reset
[log] > [mp4-remuxer]: initPTS & initDTS reset
[log] > [mp4-remuxer]: reset next timestamp
[log] > manifest codec:undefined, ADTS type:2, samplingIndex:3
[log] > parsed codec:mp4a.40.5, rate:48000, channels:2
[log] > [stream-controller]: FRAG_LOADING->PARSING
[log] > [stream-controller]: Init audio buffer, container:audio/mp4, codecs[selected/level/parsed]=[//mp4a.40.5]
[log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[/avc1.4d4028]
[log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.5)
[log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.4d4028)
[log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 207266
[log] > [stream-controller]: Loaded fragment 2 of level 0
[log] > [transmuxer.ts]: Flushed fragment 2 of level 0
[log] > [stream-controller]: PARSING->PARSED
[log] > [stream-controller]: Buffered main sn: 2 of level 0 (frag:[11.000-22.276] > buffer:[11.012-22.261])
[log] > [stream-controller]: PARSED->IDLE
[warn] > [stream-controller]: Reduce max buffer length to 300s
e.reduceMaxBufferLength @ index-e43ca4bb.js:41
[log] > [stream-controller]: Loading fragment 1 cc: 0 of [1-3] level: 0, target: 0
[log] > [stream-controller]: IDLE->FRAG_LOADING
[log] > [transmuxer-interface, main]: Starting new transmux session for sn: 1 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
        initSegmentChange: false
[log] > [mp4-remuxer]: reset next timestamp
[log] > [stream-controller]: FRAG_LOADING->PARSING
[log] > [stream-controller]: Loaded fragment 1 of level 0
[log] > [transmuxer.ts]: Flushed fragment 1 of level 0
[log] > [stream-controller]: PARSING->PARSED
[log] > [stream-controller]: Buffered main sn: 1 of level 0 (frag:[-0.261-11.012] > buffer:[3.493-22.261])
[log] > [stream-controller]: PARSED->IDLE
[log] > [stream-controller]: Loading fragment 3 cc: 0 of [1-3] level: 0, target: 22.261
[log] > [stream-controller]: IDLE->FRAG_LOADING
[log] > [transmuxer-interface, main]: Starting new transmux session for sn: 3 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: false
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 22.261255555555554
        initSegmentChange: false
[log] > [mp4-remuxer]: reset next timestamp
[log] > 2721288/2717535:unknown NAL 11 
[log] > [stream-controller]: FRAG_LOADING->PARSING
[log] > [stream-controller]: Loaded fragment 3 of level 0
[log] > [transmuxer.ts]: Flushed fragment 3 of level 0
[log] > [stream-controller]: PARSING->PARSED
[log] > [stream-controller]: Buffered main sn: 3 of level 0 (frag:[22.261-27.975] > buffer:[3.493-27.951])
[log] > [stream-controller]: PARSED->IDLE
[log] > [buffer-controller]: audio sourceBuffer now EOS
[log] > [buffer-controller]: video sourceBuffer now EOS
[log] > [buffer-controller]: Queueing mediaSource.endOfStream()
[log] > [stream-controller]: IDLE->ENDED
[log] > [buffer-controller]: Calling mediaSource.endOfStream()
[log] > [buffer-controller]: Media source ended
[warn] > skipping hole, adjusting currentTime from 0 to 3.5425
s._trySkipBufferHole @ index-e43ca4bb.js:47
s.poll @ index-e43ca4bb.js:47
e.checkBuffer @ index-e43ca4bb.js:47
e.onTickEnd @ index-e43ca4bb.js:47
e.doTick @ index-e43ca4bb.js:47
s.tick @ index-e43ca4bb.js:41
[log] > [stream-controller]: media seeking to 3.542, state: ENDED
[log] > [stream-controller]: Reset loading state
[log] > [stream-controller]: ENDED->IDLE
[log] > [audio-stream-controller]: media seeking to 3.542, state: IDLE
[log] > [subtitle-stream-controller]: media seeking to 3.542, state: IDLE
[log] > [buffer-controller]: Queueing mediaSource.endOfStream()
[log] > [stream-controller]: IDLE->ENDED
[info] > [buffer-controller]: Could not call mediaSource.endOfStream(). mediaSource.readyState: ended
[log] > [stream-controller]: Media seeked to 3.542

robwalch · 2023-07-03T18:16:18Z

I can reproduce the issue by providing a bad workerPath in the config. This appears in the logs:

hls.min.js:1 [warn] > Error in "main" Web Worker, fallback to inline

When compiling the player externally, the built in IIFE that wraps the library used to inject the worker may be removed. This results the worker setup failing. If your build and embed do not support the worker setup, either disable the worker using enableWorker: false, or provide a path to hls.worker.js matching the build version with workerPath.

JWo1F · 2023-07-03T18:21:06Z

@robwalch, thanks, it works! But why this issue is not reproducible on version <= 1.3.5?

robwalch · 2023-07-03T18:43:25Z

But why this issue is not reproducible on version <= 1.3.5?

Different worker setup and worker setup error handling I suppose.

In many cases external builds broke worker support and failed all-together. Maybe you got lucky?

Fixes #5617

robwalch · 2023-07-03T18:48:24Z

Here's a fix:

Reset loading start on worker setup error #5620

robwalch · 2023-07-03T19:44:47Z

Note that with the fix above, the segments that could not complete because of the worker setup error still get reloaded. The fix just makes sure that they are reloaded in the correct order.

Always make sure that your hls.js embed supports worker setup, otherwise disable it.

Fixes #5617 (cherry picked from commit 03bafc6)

* patch/v1.4.x: Reset loading start on worker setup error Fixes #5617 Never back-track on first fragment to avoid loop loading Fixes #5609 Only load earlier subtitle fragment if discontinuity matches Remove requirement for subtitles to be synced with media PTS when WebVTT MPEGTS map is not present Wait for level switch after fragment or key error with level switch action Fixes #5598 Reset loader aborted state on internal retry #5588 Fix issue where large subtitle target-durations result in incorrect subtitle segment selection Fixes #5595 Keep level switch error actions within player constraints Do not adjust the end time of metadata cues that overlap with cues of another type (id3, emsg, daterange) Fixes #5531 Resume fragment loading after level switch follows level error Fixes #5498

JWo1F added Bug Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Jul 3, 2023

robwalch added Confirmed Suggested-Workaround and removed Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Jul 3, 2023

robwalch added this to the 1.4.8 milestone Jul 3, 2023

robwalch added a commit that referenced this issue Jul 3, 2023

Reset loading start on worker setup error

03bafc6

Fixes #5617

robwalch mentioned this issue Jul 3, 2023

Reset loading start on worker setup error #5620

Merged

robwalch closed this as completed in #5620 Jul 3, 2023

robwalch added a commit that referenced this issue Jul 3, 2023

Reset loading start on worker setup error

94cd133

Fixes #5617 (cherry picked from commit 03bafc6)

SivanA-Kaltura mentioned this issue Nov 14, 2023

fix(SUP-39292): V7 Player v3.15.2 Shows ReferenceError kaltura/playkit-js-hls#212

Merged

5 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Playback starts from 3 seconds only in compiled form (vite) #5617

Playback starts from 3 seconds only in compiled form (vite) #5617

JWo1F commented Jul 3, 2023 •

edited

Loading

JWo1F commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023 •

edited

Loading

JWo1F commented Jul 3, 2023

JWo1F commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023

JWo1F commented Jul 3, 2023

robwalch commented Jul 3, 2023 •

edited

Loading

JWo1F commented Jul 3, 2023

robwalch commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023

robwalch commented Jul 3, 2023

Playback starts from 3 seconds only in compiled form (vite) #5617

Playback starts from 3 seconds only in compiled form (vite) #5617

Comments

JWo1F commented Jul 3, 2023 • edited Loading

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

JWo1F commented Jul 3, 2023 • edited Loading

robwalch commented Jul 3, 2023 • edited Loading

JWo1F commented Jul 3, 2023

JWo1F commented Jul 3, 2023 • edited Loading

robwalch commented Jul 3, 2023

JWo1F commented Jul 3, 2023

robwalch commented Jul 3, 2023 • edited Loading

JWo1F commented Jul 3, 2023

robwalch commented Jul 3, 2023 • edited Loading

robwalch commented Jul 3, 2023

robwalch commented Jul 3, 2023

JWo1F commented Jul 3, 2023 •

edited

Loading

JWo1F commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023 •

edited

Loading

JWo1F commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023 •

edited

Loading

robwalch commented Jul 3, 2023 •

edited

Loading