hls.js icon indicating copy to clipboard operation
hls.js copied to clipboard

bufferFullError multiple times followed by bufferStalledError

Open Renari opened this issue 9 months ago • 6 comments

What version of Hls.js are you using?

1.6.0

What browser (including version) are you using?

Brave Version 1.77.95 Chromium: 135.0.7049.52 (Official Build) (64-bit)

What OS (including version) are you using?

Arch

Test stream

Not possible because I can currently only reproduce with a copyright video, if someone wants to contact me privately I can give you a temporary stream.

Configuration

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

Additional player setup steps

None as this was reproducible in the demo at: https://hlsjs-dev.video-dev.org/demo/

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. Start playing video
  2. Wait approx 1m
  3. Video stalls while outputting both bufferFullError and bufferStalledError.

Expected behaviour

Video playback continues.

What actually happened?

Console begins printing bufferFullErrors after about 1m of playback and then eventually stalls with a bufferStalledError.

Console output

console.log

Chrome media internals output

Chrome media internals
render_id: 5571
player_id: 1
created: 2025-04-08 10:01:08.756958 UTC
origin_url: https://hlsjs-dev.video-dev.org/
kFrameUrl: https://hlsjs-dev.video-dev.org/demo/
kFrameTitle: hls.js demo
url: blob:https://hlsjs-dev.video-dev.org/0d8f5e0a-7051-4f7b-995b-4b47063afe88
info: Decoded frame with timestamp 105.021 s is out of order.
kRendererName: RendererImpl
pipeline_state: kPlaying
kVideoTracks: [object Object]
kAudioTracks: [object Object]
kIsAudioDecryptingDemuxerStream: false
kAudioDecoderName: FFmpegAudioDecoder
kIsPlatformAudioDecoder: false
debug: AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260
kIsVideoDecryptingDemuxerStream: false
kVideoDecoderName: FFmpegVideoDecoder
kIsPlatformVideoDecoder: false
dimensions: 1920x1080
kResolution: 1920x1080
duration: 3601.598
pipeline_buffering_state: [object Object]
event: kPause
kVideoPlaybackRoughness: 9.278
kVideoPlaybackFreezing: 0.043264
kFramerate: 24
video_buffering_state: [object Object]

{
  "properties": {
    "render_id": 5571,
    "player_id": 1,
    "created": "2025-04-08 10:01:08.756958 UTC",
    "origin_url": "https://hlsjs-dev.video-dev.org/",
    "kFrameUrl": "https://hlsjs-dev.video-dev.org/demo/",
    "kFrameTitle": "hls.js demo",
    "url": "blob:https://hlsjs-dev.video-dev.org/0d8f5e0a-7051-4f7b-995b-4b47063afe88",
    "info": "Decoded frame with timestamp 105.021 s is out of order.",
    "kRendererName": "RendererImpl",
    "pipeline_state": "kPlaying",
    "kVideoTracks": [
      {
        "alpha mode": "is_opaque",
        "codec": "h264",
        "coded size": "1920x1080",
        "color space": {
          "matrix": "BT709",
          "primaries": "BT709",
          "range": "LIMITED",
          "transfer": "BT709"
        },
        "encryption scheme": "Unencrypted",
        "has extra data": false,
        "hdr metadata": "unset",
        "natural size": "1920x1080",
        "orientation": "0°",
        "profile": "h264 high 10",
        "visible rect": "0,0 1920x1080"
      }
    ],
    "kAudioTracks": [
      {
        "bytes per channel": 4,
        "bytes per frame": 8,
        "channel layout": "STEREO",
        "channels": 2,
        "codec": "flac",
        "codec delay": 0,
        "discard decoder delay": true,
        "encryption scheme": "Unencrypted",
        "has extra data": true,
        "profile": "unknown",
        "sample format": "Signed 24-bit",
        "samples per second": 48000,
        "seek preroll": "0us"
      }
    ],
    "kIsAudioDecryptingDemuxerStream": false,
    "kAudioDecoderName": "FFmpegAudioDecoder",
    "kIsPlatformAudioDecoder": false,
    "debug": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260",
    "kIsVideoDecryptingDemuxerStream": false,
    "kVideoDecoderName": "FFmpegVideoDecoder",
    "kIsPlatformVideoDecoder": false,
    "dimensions": "1920x1080",
    "kResolution": "1920x1080",
    "duration": 3601.598,
    "pipeline_buffering_state": {
      "for_suspended_start": false,
      "reason": "DEMUXER_UNDERFLOW",
      "state": "BUFFERING_HAVE_NOTHING"
    },
    "event": "kPause",
    "kVideoPlaybackRoughness": 9.278,
    "kVideoPlaybackFreezing": 0.043264,
    "kFramerate": 24,
    "video_buffering_state": {
      "reason": "DEMUXER_UNDERFLOW",
      "state": "BUFFERING_HAVE_NOTHING"
    }
  },
  "events": [
    {
      "time": 0,
      "key": "created",
      "value": "2025-04-08 10:01:08.756958 UTC"
    },
    {
      "time": 0.05300000309944153,
      "key": "origin_url",
      "value": "https://hlsjs-dev.video-dev.org/"
    },
    {
      "time": 0.05500000715255737,
      "key": "kFrameUrl",
      "value": "https://hlsjs-dev.video-dev.org/demo/"
    },
    {
      "time": 0.056999996304512024,
      "key": "kFrameTitle",
      "value": "hls.js demo"
    },
    {
      "time": 0.08799999952316284,
      "key": "url",
      "value": "blob:https://hlsjs-dev.video-dev.org/0d8f5e0a-7051-4f7b-995b-4b47063afe88"
    },
    {
      "time": 0.0990000069141388,
      "key": "info",
      "value": "ChunkDemuxer"
    },
    {
      "time": 0.10500000417232513,
      "key": "kRendererName",
      "value": "RendererImpl"
    },
    {
      "time": 0.1120000034570694,
      "key": "pipeline_state",
      "value": "kStarting"
    },
    {
      "time": 133.68299999833107,
      "key": "kVideoTracks",
      "value": [
        {
          "alpha mode": "is_opaque",
          "codec": "h264",
          "coded size": "1920x1080",
          "color space": {
            "matrix": "BT709",
            "primaries": "BT709",
            "range": "LIMITED",
            "transfer": "BT709"
          },
          "encryption scheme": "Unencrypted",
          "has extra data": false,
          "hdr metadata": "unset",
          "natural size": "1920x1080",
          "orientation": "0°",
          "profile": "h264 high 10",
          "visible rect": "0,0 1920x1080"
        }
      ]
    },
    {
      "time": 133.70000000298023,
      "key": "kAudioTracks",
      "value": [
        {
          "bytes per channel": 4,
          "bytes per frame": 8,
          "channel layout": "STEREO",
          "channels": 2,
          "codec": "flac",
          "codec delay": 0,
          "discard decoder delay": true,
          "encryption scheme": "Unencrypted",
          "has extra data": true,
          "profile": "unknown",
          "sample format": "Signed 24-bit",
          "samples per second": 48000,
          "seek preroll": "0us"
        }
      ]
    },
    {
      "time": 134.5700000077486,
      "key": "kIsAudioDecryptingDemuxerStream",
      "value": false
    },
    {
      "time": 134.57100000977516,
      "key": "kAudioDecoderName",
      "value": "FFmpegAudioDecoder"
    },
    {
      "time": 134.57199999690056,
      "key": "kIsPlatformAudioDecoder",
      "value": false
    },
    {
      "time": 134.5780000090599,
      "key": "info",
      "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: flac, profile: unknown, bytes_per_channel: 4, channel_layout: STEREO, channels: 2, samples_per_second: 48000, sample_format: Signed 24-bit, bytes_per_frame: 8, seek_preroll: 0us, codec_delay: 0, has extra data: true, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false"
    },
    {
      "time": 134.5920000076294,
      "key": "debug",
      "value": "Video rendering in low delay mode."
    },
    {
      "time": 134.60700000822544,
      "key": "info",
      "value": "Cannot select DecryptingVideoDecoder for video decoding"
    },
    {
      "time": 134.61300000548363,
      "key": "info",
      "value": "Cannot select VaapiVideoDecoder for video decoding"
    },
    {
      "time": 134.625,
      "key": "info",
      "value": "Cannot select VpxVideoDecoder for video decoding"
    },
    {
      "time": 134.6300000101328,
      "key": "info",
      "value": "Cannot select Dav1dVideoDecoder for video decoding"
    },
    {
      "time": 134.85500000417233,
      "key": "kIsVideoDecryptingDemuxerStream",
      "value": false
    },
    {
      "time": 134.85600000619888,
      "key": "kVideoDecoderName",
      "value": "FFmpegVideoDecoder"
    },
    {
      "time": 134.85700000822544,
      "key": "kIsPlatformVideoDecoder",
      "value": false
    },
    {
      "time": 134.8669999986887,
      "key": "info",
      "value": "Selected FFmpegVideoDecoder for video decoding, config: codec: h264, profile: h264 high 10, level: not available, alpha_mode: is_opaque, coded size: [1920,1080], visible rect: [0,0,1920,1080], natural size: [1920,1080], has extra data: false, encryption scheme: Unencrypted, rotation: 0°, flipped: 0, color space: {primaries:BT709, transfer:BT709, matrix:BT709, range:LIMITED}"
    },
    {
      "time": 134.87700000405312,
      "key": "pipeline_state",
      "value": "kPlaying"
    },
    {
      "time": 192.75200000405312,
      "key": "dimensions",
      "value": "1920x1080"
    },
    {
      "time": 192.7559999972582,
      "key": "kResolution",
      "value": "1920x1080"
    },
    {
      "time": 192.90399999916553,
      "key": "info",
      "value": "Effective playback rate changed from 0 to 1"
    },
    {
      "time": 216.14000000059605,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 280.93899999558926,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 364.54100000858307,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 433.61599999666214,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 52.27099999785423,
      "key": "duration",
      "value": 3601.598
    },
    {
      "time": 192.79399999976158,
      "key": "pipeline_buffering_state",
      "value": {
        "for_suspended_start": false,
        "state": "BUFFERING_HAVE_ENOUGH"
      }
    },
    {
      "time": 192.94200000166893,
      "key": "event",
      "value": "kPlay"
    },
    {
      "time": 141.82100000977516,
      "key": "event",
      "value": "kPause"
    },
    {
      "time": 4492.747999995947,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 14772.626000002027,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 25241.22200000286,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 35538.95600000024,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 36659.118000000715,
      "key": "debug",
      "value": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 47068.060000002384,
      "key": "debug",
      "value": "(Log limit reached. Further similar entries may be suppressed): ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite."
    },
    {
      "time": 100381.20300000906,
      "key": "kVideoPlaybackRoughness",
      "value": 4.508
    },
    {
      "time": 100381.20600000024,
      "key": "kVideoPlaybackFreezing",
      "value": 0.043266
    },
    {
      "time": 100381.20700000226,
      "key": "kFramerate",
      "value": 24
    },
    {
      "time": 105290.21700000763,
      "key": "info",
      "value": "Decoded frame with timestamp 105.021 s is out of order."
    },
    {
      "time": 127603.08100000024,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=15084801 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1373578"
    },
    {
      "time": 127660.57400000095,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=15084801 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1373578"
    },
    {
      "time": 127752.3030000031,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 127818.21400000155,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 127881.86300000548,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 127951.27500000596,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128027.58599999547,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128095.45900000632,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128158.89800000191,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128225.51800000668,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128294.64800000191,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128361.8180000037,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128423.03700000048,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128484.03300000727,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 128554.78300000727,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 127729.63899999857,
      "key": "video_buffering_state",
      "value": {
        "reason": "DEMUXER_UNDERFLOW",
        "state": "BUFFERING_HAVE_NOTHING"
      }
    },
    {
      "time": 128616.66200000048,
      "key": "debug",
      "value": "AUDIO stream: new append of newDataSize=12773609 bytes exceeds memory_limit_=12582912, currently buffered ranges_size=1703260"
    },
    {
      "time": 130729.72400000691,
      "key": "pipeline_buffering_state",
      "value": {
        "for_suspended_start": false,
        "reason": "DEMUXER_UNDERFLOW",
        "state": "BUFFERING_HAVE_NOTHING"
      }
    },
    {
      "time": 130729.72599999607,
      "key": "kVideoPlaybackRoughness",
      "value": 9.278
    },
    {
      "time": 130729.75100000203,
      "key": "kVideoPlaybackFreezing",
      "value": 0.043264
    },
    {
      "time": 130729.75200000405,
      "key": "kFramerate",
      "value": 24
    }
  ]
}

Renari avatar Apr 08 '25 10:04 Renari

CC: https://github.com/jellyfin/jellyfin-web/issues/4866

Renari avatar Apr 08 '25 10:04 Renari

Hi @Renari. Can you share the contents of the multivariant playlist?

From the logs, it looks like you have a 10Mbit stream wih h264 video and FLaC audio:

1080p SDR avc1,flac @10014786

There are warnings indicating that there is alternate audio (although that may be incorrect), and the main playlist contains muxed audio and video:

stream-controller.ts:1358 [warn] > [stream-controller]: Media segment with muxed audiovideo where only video expected:

The issue starts on msn 13 which is a 10 second segment. It appends once, but after this the buffer full errors begin:

Buffered main sn: 13 of level 0 (frag:[117.247-127.633] > buffer:[56.319-127.658])

Eventually there is an attempt to empty the buffer:

base-stream-controller.ts:1868 [warn] > [stream-controller]: Buffer full error while media.currentTime is not buffered, flush main buffer

But after emptying the buffer, the 10 second segment is appended but the buffer remains "empty"

base-stream-controller.ts:708 [log] > [stream-controller]: Buffered main sn: 13 of level 0 (frag:[117.247-127.633] > buffer:)

Looks like an MSE bug on this platform related to the ~100Mbit segment. You should look more closely at the packaging and segmenting of this content. 10 second segments are not appropriate for this high a bitrate, and if the combined buffer is not changing on append, there could be an issue with the alignment of audio video in the muxed segment resulting in the buffer allocation getting filled with no overlapping playable media.

You might try calling recoverMediaError() at this point, or test if playback can start at segment 13 (startPosition: 128). If not you've got a playlist packaged in a way that MSE browsers cannot handle.

robwalch avatar Apr 08 '25 18:04 robwalch

Not possible because I can currently only reproduce with a copyright video, if someone wants to contact me privately I can give you a temporary stream.

You can reach out to me on video-dev slack.

robwalch avatar Apr 08 '25 18:04 robwalch

m3u8.zip

Here's the two relevant m3u8, I also sent you a dm on slack.

Renari avatar Apr 08 '25 18:04 Renari

Not yet confirmed, but we'll see what we can do in the next patch.

robwalch avatar Apr 08 '25 19:04 robwalch

Removing the milestone as the sample provided does not appear to be packaged properly (bad segment timestamps / unmarked discontinuities / unclear if muxed audio and video samples align). Most of the segments won't append anything in Chrome independently.

robwalch avatar Apr 09 '25 02:04 robwalch

Closing as only playlists were provided and the logs show issues with packaging.

robwalch avatar Jul 02 '25 21:07 robwalch