Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LoadStats properties loaded and total is 0 for a download fragment when using FetchLoader #5050

Closed
3 of 5 tasks
ken-bam opened this issue Nov 22, 2022 · 3 comments · Fixed by #5054
Closed
3 of 5 tasks

Comments

@ken-bam
Copy link

ken-bam commented Nov 22, 2022

What version of Hls.js are you using?

1.2.7

What browser (including version) are you using?

Chrome 107.0.5304.110 (Official Build) (x86_64)

What OS (including version) are you using?

macOS Version 12.6.1(21G217)

Test stream

https://labs.bambuser.com/kristian/hlsjs/hlsjs_bug_report.html

Configuration

{
  progressive: true,
  debug: true,
  lowLatencyMode: false,
}

Additional player setup steps

Test page setup:

<html>
  <head>
    <title>Hls.js bug report</title>
  </head>

  <body>
    <script src="https://cdn.jsdelivr.net/npm/hls.js@latest"></script>

    <center>
      <h1>Hls.js bug report</h1>
      <video height="600" id="video" controls></video>
    </center>

    <script>
      var video = document.getElementById('video');
      if (Hls.isSupported()) {
        var hls = new Hls({
          progressive: true,
          debug: true,
          lowLatencyMode: false, 
        });
        hls.loadSource('https://test-streams.mux.dev/x36xhzz/x36xhzz.m3u8');
        hls.attachMedia(video);
        hls.on(Hls.Events.MEDIA_ATTACHED, function () {
          video.muted = true;
          video.play();
        });
        hls.on(Hls.Events.FRAG_LOADED, (event, data) => {
          if (!data.frag.stats) return;
          console.log('Stats: loaded: ' + data.frag.stats.loaded + ' total: ' + data.frag.stats.total);
        });
      } else {
        console.log('Hls.js not supported');
      }
    </script>
</body>
</html>

Checklist

Steps to reproduce

  1. Load test page provided on: https://labs.bambuser.com/kristian/hlsjs/hlsjs_bug_report.html
  2. Start playback
  3. Observe the console window for Stats: loaded: ' + 0 + ' total: ' + 0 log rows.

Expected behaviour

The LoadStats loaded and total properties for a downloaded Fragment shall be > 0 bytes, also when configuration option progressive is true, i.e FetchLoader is used.

What actually happened?

The LoadStats class loaded and total properties for any downloaded Fragment is 0 bytes.

The 0 in loaded and total seems to originate from that loadProgressively in FetchLoader resolves to an empty ArrayBuyffer here:

return Promise.resolve(new ArrayBuffer(0));
which 0 length is then written to stats.loaded and stats.total here:
stats.loaded = stats.total = responseData[LENGTH];
in load and effectively resets the current loaded and total bytes downloaded.

Console output

[log] > Debug logs enabled for "Hls instance"
hls.js@latest:1 [log] > [config]: Progressive streaming enabled, using FetchLoader
hls.js@latest:1 [log] > stopLoad
hls.js@latest:1 [log] > loadSource:https://test-streams.mux.dev/x36xhzz/x36xhzz.m3u8
hls.js@latest:1 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.js@latest:1 [log] > attachMedia
hls.js@latest:1 [log] > [buffer-controller]: Media source opened
hls.js@latest:1 [log] > [subtitle-stream-controller]: STOPPED->IDLE
hls.js@latest:1 [log] > [level-controller]: manifest loaded, 5 level(s) found, first bitrate: 2149280
hls.js@latest:1 [log] > 1 bufferCodec event(s) expected
hls.js@latest:1 [log] > startLoad(-1)
hls.js@latest:1 [log] > [level-controller]: switching to level 3 from -1
hls.js@latest:1 [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
hls.js@latest:1 [log] > [stream-controller]: STOPPED->IDLE
hls.js@latest:1 [log] > [subtitle-stream-controller]: IDLE->STOPPED
hls.js@latest:1 [log] > [subtitle-stream-controller]: STOPPED->IDLE
hls.js@latest:1 [log] > [stream-controller]: Level 3 loaded [0,63], cc [0, 0] duration:634.584
hls.js@latest:1 [log] > [buffer-controller]: Updating Media Source duration to 634.584
hls.js@latest:1 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-63] level: 3, target: 0
hls.js@latest:1 [log] > [stream-controller]: IDLE->FRAG_LOADING
hls.js@latest:1 [log] > demuxing in webworker
hls.js@latest:1 [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
hls.js@latest:1 [log] > [stream-controller]: Loaded fragment 0 of level 3
hlsjs_bug_report.html:30 Stats: loaded: 0 total: 0
dc0d12cd-aa68-465e-bb81-f543215fe389:1 [log] > Debug logs enabled for "main"
hls.js@latest:1 [log] > [mp4-remuxer]: ISGenerated flag reset
hls.js@latest:1 [log] > [mp4-remuxer]: initPTS & initDTS reset
hls.js@latest:1 [log] > manifest codec:mp4a.40.2, ADTS type:2, samplingIndex:4
hls.js@latest:1 [log] > parsed codec:mp4a.40.5, rate:44100, channels:2
hls.js@latest:1 [log] > [stream-controller]: FRAG_LOADING->PARSING
hls.js@latest:1 [log] > [stream-controller]: Init audio buffer, container:audio/mp4, codecs[selected/level/parsed]=[mp4a.40.2/mp4a.40.2/mp4a.40.5]
hls.js@latest:1 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.64001f/avc1.64001f]
hls.js@latest:1 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.2)
hls.js@latest:1 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.64001f)
hls.js@latest:1 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 900909
hls.js@latest:1 [log] > [transmuxer.ts]: Flushed fragment 0 of level 3
hls.js@latest:1 [log] > [stream-controller]: PARSING->PARSED
hls.js@latest:1 [log] > [stream-controller]: Buffered main sn: 0 of level 3 [0.023,10.008]
hls.js@latest:1 [log] > [stream-controller]: PARSED->IDLE
hls.js@latest:1 [log] > [level-controller]: switching to level 0 from 3
hls.js@latest:1 [log] > [level-controller]: Attempt loading level index 0 with URL-id 0 https://test-streams.mux.dev/x36xhzz/url_2/193039199_mp4_h264_aac_ld_7.m3u8
hls.js@latest:1 [log] > [stream-controller]: IDLE->WAITING_LEVEL
hls.js@latest:1 [log] > [stream-controller]: Level 0 loaded [0,63], cc [0, 0] duration:634.634
hls.js@latest:1 [log] > [stream-controller]: WAITING_LEVEL->IDLE
hls.js@latest:1 [log] > [stream-controller]: Loading fragment 1 cc: 0 of [0-63] level: 0, target: 10.008
hls.js@latest:1 [log] > [stream-controller]: IDLE->FRAG_LOADING
hls.js@latest:1 [warn] > skipping hole, adjusting currentTime from 0 to 0.1
e._trySkipBufferHole @ hls.js@latest:1
e.poll @ hls.js@latest:1
u.checkBuffer @ hls.js@latest:1
u.onTickEnd @ hls.js@latest:1
u.doTick @ hls.js@latest:1
e.tick @ hls.js@latest:1
u.onLevelLoaded @ hls.js@latest:1
o.emit @ hls.js@latest:1
a.emit @ hls.js@latest:1
a.trigger @ hls.js@latest:1
e.handlePlaylistLoaded @ hls.js@latest:1
e.handleTrackOrLevelPlaylist @ hls.js@latest:1
e.loadsuccess @ hls.js@latest:1
(anonymous) @ hls.js@latest:1
Promise.then (async)
e.load @ hls.js@latest:1
e.load @ hls.js@latest:1
e.onLevelLoading @ hls.js@latest:1
o.emit @ hls.js@latest:1
a.emit @ hls.js@latest:1
a.trigger @ hls.js@latest:1
l.loadPlaylist @ hls.js@latest:1
set @ hls.js@latest:1
set @ hls.js@latest:1
set @ hls.js@latest:1
u.doTickIdle @ hls.js@latest:1
u.doTick @ hls.js@latest:1
e.tick @ hls.js@latest:1
h.fragBufferedComplete @ hls.js@latest:1
u.onFragBuffered @ hls.js@latest:1
o.emit @ hls.js@latest:1
a.emit @ hls.js@latest:1
a.trigger @ hls.js@latest:1
(anonymous) @ hls.js@latest:1
(anonymous) @ hls.js@latest:1
Promise.then (async)
e.blockBuffers @ hls.js@latest:1
e.onFragParsed @ hls.js@latest:1
o.emit @ hls.js@latest:1
a.emit @ hls.js@latest:1
a.trigger @ hls.js@latest:1
h.updateLevelTiming @ hls.js@latest:1
h._handleTransmuxerFlush @ hls.js@latest:1
e.onWorkerMessage @ hls.js@latest:1
hls.js@latest:1 [log] > [buffer-controller]: Updating Media Source duration to 634.634
hls.js@latest:1 [log] > [stream-controller]: media seeking to 0.100, state: FRAG_LOADING
hls.js@latest:1 [log] > [audio-stream-controller]: media seeking to 0.100, state: STOPPED
hls.js@latest:1 [log] > [subtitle-stream-controller]: media seeking to 0.100, state: IDLE
hls.js@latest:1 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 1 p: -1 level: 0 id: 1
        discontinuity: false
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 10
        initSegmentChange: false
hls.js@latest:1 [log] > [stream-controller]: Loaded fragment 1 of level 0
hlsjs_bug_report.html:30 Stats: loaded: 0 total: 0
hls.js@latest:1 [log] > [mp4-remuxer]: ISGenerated flag reset
hls.js@latest:1 [log] > [mp4-remuxer]: reset next timestamp
hls.js@latest:1 [log] > [mp4-remuxer]: ISGenerated flag reset
hls.js@latest:1 [log] > [mp4-remuxer]: initPTS & initDTS reset
hls.js@latest:1 [log] > manifest codec:mp4a.40.5, ADTS type:2, samplingIndex:7
hls.js@latest:1 [log] > parsed codec:mp4a.40.5, rate:22050, channels:2
hls.js@latest:1 [log] > [stream-controller]: FRAG_LOADING->PARSING
hls.js@latest:1 [log] > [stream-controller]: Init audio buffer, container:audio/mp4, codecs[selected/level/parsed]=[mp4a.40.5/mp4a.40.5/mp4a.40.5]
hls.js@latest:1 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.42000d/avc1.42c00d]
hls.js@latest:1 [log] > [buffer-controller]: changing audio sourceBuffer type to audio/mp4;codecs=mp4a.40.5
hls.js@latest:1 [log] > [buffer-controller]: switching codec mp4a.40.2 to mp4a.40.5
hls.js@latest:1 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
hls.js@latest:1 [log] > [stream-controller]: PARSING->PARSED
hls.js@latest:1 [log] > [stream-controller]: Buffered main sn: 1 of level 0 [0.023,19.990]
hls.js@latest:1 [log] > [stream-controller]: PARSED->IDLE
hls.js@latest:1 [log] > [stream-controller]: Loading fragment 2 cc: 0 of [0-63] level: 0, target: 19.99
hls.js@latest:1 [log] > [stream-controller]: IDLE->FRAG_LOADING
hls.js@latest:1 [log] > [stream-controller]: Media seeked to 0.122
hls.js@latest:1 [log] > [stream-controller]: Loaded fragment 2 of level 0
hlsjs_bug_report.html:30 Stats: loaded: 0 total: 0
hls.js@latest:1 [log] > [stream-controller]: FRAG_LOADING->PARSING
hls.js@latest:1 [log] > [transmuxer.ts]: Flushed fragment 2 of level 0
hls.js@latest:1 [log] > [stream-controller]: PARSING->PARSED
hls.js@latest:1 [log] > [stream-controller]: Buffered main sn: 2 of level 0 [0.023,29.977]
hls.js@latest:1 [log] > [stream-controller]: PARSED->IDLE
hls.js@latest:1 [log] > [stream-controller]: Loading fragment 3 cc: 0 of [0-63] level: 0, target: 29.977
hls.js@latest:1 [log] > [stream-controller]: IDLE->FRAG_LOADING
hls.js@latest:1 [log] > [stream-controller]: Loaded fragment 3 of level 0
hlsjs_bug_report.html:30 Stats: loaded: 0 total: 0

Chrome media internals output

No response

@ken-bam ken-bam added Bug Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Nov 22, 2022
@robwalch robwalch added this to the 1.2.8 milestone Nov 23, 2022
@robwalch robwalch added Confirmed and removed Needs Triage If there is a suspected stream issue, apply this label to triage if it is something we should fix. labels Nov 23, 2022
@robwalch
Copy link
Collaborator

When progressive: true is used, all data is transferred on progress. The stats should still have the loaded and total bytes on frag loaded, but the data itself is no longer available. It had been read from the ReadableSream presented in the networkDetails Response body.

@robwalch robwalch added the Verify Fixed An unreleased bug fix has been merged and should be verified before closing. label Nov 23, 2022
@robwalch
Copy link
Collaborator

Hi @ken-bam,

#5054 should address the issue. Thanks for reporting it.

If you would like to use the fetch-loader in the latest release without this issue I recommend disabling the progressive option.

@ken-bam
Copy link
Author

ken-bam commented Nov 23, 2022

@robwalch I have tested #5054 and now it works as expected. Thanks for the fix.

robwalch added a commit that referenced this issue Nov 28, 2022
…5054)

Fixes #5050

Co-authored-by: Rob Walch <rob@jwplayer.com>
robwalch added a commit that referenced this issue Nov 28, 2022
…5054)

Fixes #5050

Co-authored-by: Rob Walch <rob@jwplayer.com>
@robwalch robwalch removed the Verify Fixed An unreleased bug fix has been merged and should be verified before closing. label Nov 28, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants