video-dev / hls.js

HLS.js is a JavaScript library that plays HLS in browsers with support for MSE.
https://hlsjs.video-dev.org/demo
Other
14.63k stars 2.56k forks source link

macOS decoding error: PIPELINE_ERROR_DECODE: VDA Error 4 #5632

Closed iameli closed 1 year ago

iameli commented 1 year ago

What version of Hls.js are you using?

v1.4.7

What browser (including version) are you using?

Latest Brave & Firefox on macOS

What OS (including version) are you using?

macOS Ventura 13.3.1 (a)

Test stream

https://docs-livepeer-live-cors.livepeer.workers.dev/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/problem.m3u8

Configuration

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

Additional player setup steps

Seems to break in all cases where macOS hardware decoding is involved. Using software decoding in an Ubuntu VM, I get a hiccup in the video but nothing fatal. On Windows using NVDEC I get completely clean playback; this is consistent with the original encoder being NVENC.

Checklist

Steps to reproduce

Just playback the stream at https://docs-livepeer-live-cors.livepeer.workers.dev/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/problem.m3u8

Expected behaviour

Clean playback

What actually happened?

Console output

5.446 | Media element detached
5.449 | Loading https://docs-livepeer-live-cors.livepeer.workers.dev/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/problem.m3u8
5.45 | Loading manifest and attaching video element...
5.463 | 1 quality levels found
5.463 | Manifest successfully loaded
5.484 | Media element attached, trying to recover media error.
11.65 | Media element detached
11.65 | The video playback was aborted due to a corruption problem or because the video used features your browser did not support - PIPELINE_ERROR_DECODE: VDA Error 4
11.654 | Media element attached, trying to swap audio codec and recover media error.
12.034 | Media element detached
12.036 | The video playback was aborted due to a corruption problem or because the video used features your browser did not support - PIPELINE_ERROR_DECODE: VDA Error 4
12.047 | Media element attached, cannot recover. Last media error recovery failed.
12.426 | The video playback was aborted due to a corruption problem or because the video used features your browser did not support - PIPELINE_ERROR_DECODE: VDA Error 4

Chrome media internals output

{
  "properties": {
    "render_id": 1655,
    "player_id": 11,
    "created": "2023-07-06 17:55:57.476 UTC",
    "origin_url": "https://hlsjs.video-dev.org/",
    "kFrameUrl": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ==",
    "kFrameTitle": "hls.js demo",
    "url": "blob:https://hlsjs.video-dev.org/07aac4ef-1f4e-47bd-9e17-c1076ad0679b",
    "kTextTracks": [],
    "info": "Effective playback rate changed from 0 to 1",
    "kRendererName": "RendererImpl",
    "pipeline_state": "kStopped",
    "kAudioTracks": [
      {
        "bytes per channel": 2,
        "bytes per frame": 4,
        "channel layout": "STEREO",
        "channels": 2,
        "codec": "aac",
        "codec delay": 0,
        "discard decoder delay": false,
        "encryption scheme": "Unencrypted",
        "has extra data": false,
        "profile": "unknown",
        "sample format": "Signed 16-bit",
        "samples per second": 48000,
        "seek preroll": "0us"
      }
    ],
    "kVideoTracks": [
      {
        "alpha mode": "is_opaque",
        "codec": "h264",
        "coded size": "3840x2160",
        "color space": {
          "matrix": "BT709",
          "primaries": "BT709",
          "range": "LIMITED",
          "transfer": "BT709"
        },
        "encryption scheme": "Unencrypted",
        "has extra data": false,
        "hdr metadata": "unset",
        "natural size": "3840x2160",
        "orientation": "0°",
        "profile": "h264 high",
        "visible rect": "0,0 3840x2160"
      }
    ],
    "kIsAudioDecryptingDemuxerStream": false,
    "kAudioDecoderName": "FFmpegAudioDecoder",
    "kIsPlatformAudioDecoder": false,
    "kIsVideoDecryptingDemuxerStream": false,
    "kVideoDecoderName": "VDAVideoDecoder",
    "kIsPlatformVideoDecoder": true,
    "debug": "ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite.",
    "seek_target": 5.810637,
    "dimensions": "3840x2160",
    "kResolution": "3840x2160",
    "event": "kPause",
    "error": {
      "cause": {
        "code": 1,
        "data": {},
        "group": "DecoderStatus",
        "message": "",
        "stack": [
          {
            "file": "media/gpu/ipc/service/vda_video_decoder.cc",
            "line": 919
          }
        ]
      },
      "code": 3,
      "data": {},
      "group": "PipelineStatus",
      "message": "",
      "stack": [
        {
          "file": "media/renderers/video_renderer_impl.cc",
          "line": 591
        }
      ]
    },
    "duration": 15.007999,
    "pipeline_buffering_state": {
      "for_suspended_start": false,
      "state": "BUFFERING_HAVE_ENOUGH"
    }
  },
  "events": [
    {
      "time": 0,
      "key": "created",
      "value": "2023-07-06 17:55:57.476 UTC"
    },
    {
      "time": 0.1940000057220459,
      "key": "origin_url",
      "value": "https://hlsjs.video-dev.org/"
    },
    {
      "time": 0.19699999690055847,
      "key": "kFrameUrl",
      "value": "https://hlsjs.video-dev.org/demo/?src=https%3A%2F%2Ftest-streams.mux.dev%2Fx36xhzz%2Fx36xhzz.m3u8&demoConfig=eyJlbmFibGVTdHJlYW1pbmciOnRydWUsImF1dG9SZWNvdmVyRXJyb3IiOnRydWUsInN0b3BPblN0YWxsIjpmYWxzZSwiZHVtcGZNUDQiOmZhbHNlLCJsZXZlbENhcHBpbmciOi0xLCJsaW1pdE1ldHJpY3MiOi0xfQ=="
    },
    {
      "time": 0.19900000095367432,
      "key": "kFrameTitle",
      "value": "hls.js demo"
    },
    {
      "time": 0.3269999921321869,
      "key": "url",
      "value": "blob:https://hlsjs.video-dev.org/07aac4ef-1f4e-47bd-9e17-c1076ad0679b"
    },
    {
      "time": 0.3310000002384186,
      "key": "kTextTracks",
      "value": []
    },
    {
      "time": 0.33799999952316284,
      "key": "info",
      "value": "ChunkDemuxer"
    },
    {
      "time": 0.3439999967813492,
      "key": "kRendererName",
      "value": "RendererImpl"
    },
    {
      "time": 0.5300000011920929,
      "key": "pipeline_state",
      "value": "kStarting"
    },
    {
      "time": 101.41899999976158,
      "key": "kAudioTracks",
      "value": [
        {
          "bytes per channel": 2,
          "bytes per frame": 4,
          "channel layout": "STEREO",
          "channels": 2,
          "codec": "aac",
          "codec delay": 0,
          "discard decoder delay": false,
          "encryption scheme": "Unencrypted",
          "has extra data": false,
          "profile": "unknown",
          "sample format": "Signed 16-bit",
          "samples per second": 48000,
          "seek preroll": "0us"
        }
      ]
    },
    {
      "time": 101.87800000607967,
      "key": "kVideoTracks",
      "value": [
        {
          "alpha mode": "is_opaque",
          "codec": "h264",
          "coded size": "3840x2160",
          "color space": {
            "matrix": "BT709",
            "primaries": "BT709",
            "range": "LIMITED",
            "transfer": "BT709"
          },
          "encryption scheme": "Unencrypted",
          "has extra data": false,
          "hdr metadata": "unset",
          "natural size": "3840x2160",
          "orientation": "0°",
          "profile": "h264 high",
          "visible rect": "0,0 3840x2160"
        }
      ]
    },
    {
      "time": 107.00499999523163,
      "key": "kIsAudioDecryptingDemuxerStream",
      "value": false
    },
    {
      "time": 107.0080000013113,
      "key": "kAudioDecoderName",
      "value": "FFmpegAudioDecoder"
    },
    {
      "time": 107.00900000333786,
      "key": "kIsPlatformAudioDecoder",
      "value": false
    },
    {
      "time": 107.0160000026226,
      "key": "info",
      "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: aac, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 48000, sample_format: Signed 16-bit, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: false, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: true"
    },
    {
      "time": 107.04700000584126,
      "key": "info",
      "value": "Cannot select DecryptingVideoDecoder for video decoding"
    },
    {
      "time": 135.83300000429153,
      "key": "kIsVideoDecryptingDemuxerStream",
      "value": false
    },
    {
      "time": 135.89200000464916,
      "key": "kVideoDecoderName",
      "value": "VDAVideoDecoder"
    },
    {
      "time": 135.89299999177456,
      "key": "kIsPlatformVideoDecoder",
      "value": true
    },
    {
      "time": 135.90299999713898,
      "key": "info",
      "value": "Selected VDAVideoDecoder for video decoding, config: codec: h264, profile: h264 high, level: not available, alpha_mode: is_opaque, coded size: [3840,2160], visible rect: [0,0,3840,2160], natural size: [3840,2160], has extra data: false, encryption scheme: Unencrypted, rotation: 0°, flipped: 0, color space: {primaries:BT709, transfer:BT709, matrix:BT709, range:LIMITED}"
    },
    {
      "time": 135.91499999165535,
      "key": "pipeline_state",
      "value": "kPlaying"
    },
    {
      "time": 153.00900000333786,
      "key": "debug",
      "value": "Prepared video sample is not conformant"
    },
    {
      "time": 153.01299999654293,
      "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": 164.74899999797344,
      "key": "seek_target",
      "value": 5.810637
    },
    {
      "time": 164.8180000036955,
      "key": "pipeline_state",
      "value": "kSeeking"
    },
    {
      "time": 164.9599999934435,
      "key": "pipeline_state",
      "value": "kPlaying"
    },
    {
      "time": 251.76099999248981,
      "key": "dimensions",
      "value": "3840x2160"
    },
    {
      "time": 251.76500000059605,
      "key": "kResolution",
      "value": "3840x2160"
    },
    {
      "time": 255.27300000190735,
      "key": "info",
      "value": "Effective playback rate changed from 0 to 1"
    },
    {
      "time": 255.37700000405312,
      "key": "event",
      "value": "kPlay"
    },
    {
      "time": 522.7230000048876,
      "key": "error",
      "value": "VDA Error 4"
    },
    {
      "time": 522.7939999997616,
      "key": "error",
      "value": {
        "code": 1,
        "data": {},
        "group": "DecoderStatus",
        "message": "",
        "stack": [
          {
            "file": "media/gpu/ipc/service/vda_video_decoder.cc",
            "line": 919
          }
        ]
      }
    },
    {
      "time": 522.8069999963045,
      "key": "error",
      "value": "video decode error!"
    },
    {
      "time": 522.8859999924898,
      "key": "error",
      "value": {
        "cause": {
          "code": 1,
          "data": {},
          "group": "DecoderStatus",
          "message": "",
          "stack": [
            {
              "file": "media/gpu/ipc/service/vda_video_decoder.cc",
              "line": 919
            }
          ]
        },
        "code": 3,
        "data": {},
        "group": "PipelineStatus",
        "message": "",
        "stack": [
          {
            "file": "media/renderers/video_renderer_impl.cc",
            "line": 591
          }
        ]
      }
    },
    {
      "time": 523.027999997139,
      "key": "pipeline_state",
      "value": "kStopping"
    },
    {
      "time": 523.2479999959469,
      "key": "event",
      "value": "kPause"
    },
    {
      "time": 523.3770000040531,
      "key": "pipeline_state",
      "value": "kStopped"
    },
    {
      "time": 221.16499999165535,
      "key": "duration",
      "value": 15.007999
    },
    {
      "time": 255.2099999934435,
      "key": "pipeline_buffering_state",
      "value": {
        "for_suspended_start": false,
        "state": "BUFFERING_HAVE_ENOUGH"
      }
    }
  ]
}

EDIT: My encoder settings for this stream, just in case that matters. 12 Mbps 4k60 with B-Frames disabled.

image

EDIT 2: Shaka Player and Bitmovin's HLS Player seem to run into this issue as well. But THEOplayer doesn't! Fascinating.

iameli commented 1 year ago

Here's the transmuxed fMP4 dumped from the player. Attempting to decode that with VideoToolbox-accelerated ffmpeg causes problems.

ffmpeg version 6.0 Copyright (c) 2000-2023 the FFmpeg developers
  built with Apple clang version 14.0.3 (clang-1403.0.22.14.1)
  configuration: --prefix=/opt/homebrew/Cellar/ffmpeg/6.0 --enable-shared --enable-pthreads --enable-version3 --cc=clang --host-cflags= --host-ldflags= --enable-ffplay --enable-gnutls --enable-gpl --enable-libaom --enable-libaribb24 --enable-libbluray --enable-libdav1d --enable-libmp3lame --enable-libopus --enable-librav1e --enable-librist --enable-librubberband --enable-libsnappy --enable-libsrt --enable-libsvtav1 --enable-libtesseract --enable-libtheora --enable-libvidstab --enable-libvmaf --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-lzma --enable-libfontconfig --enable-libfreetype --enable-frei0r --enable-libass --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libspeex --enable-libsoxr --enable-libzmq --enable-libzimg --disable-libjack --disable-indev=jack --enable-videotoolbox --enable-neon
  libavutil      58.  2.100 / 58.  2.100
  libavcodec     60.  3.100 / 60.  3.100
  libavformat    60.  3.100 / 60.  3.100
  libavdevice    60.  1.100 / 60.  1.100
  libavfilter     9.  3.100 /  9.  3.100
  libswscale      7.  1.100 /  7.  1.100
  libswresample   4. 10.100 /  4. 10.100
  libpostproc    57.  1.100 / 57.  1.100
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x139804f80] Duplicated SDTP atom
    Last message repeated 1 times
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x139804f80] Found duplicated MOOV Atom. Skipped it
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x139804f80] Duplicated SDTP atom
    Last message repeated 1 times
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x139804f80] Found duplicated MOOV Atom. Skipped it
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x139804f80] Duplicated SDTP atom
    Last message repeated 1 times
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'video-2023-07-06T18_12_05.397Z.mp4':
  Metadata:
    creation_time   : 1970-01-01T00:00:02.000000Z
    minor_version   : 1
    major_brand     : isom
    compatible_brands: isomavc1
  Duration: 00:00:15.00, start: 0.000000, bitrate: 28022 kb/s
  Stream #0:0[0x1](und): Video: h264 (High) (avc1 / 0x31637661), yuv420p(tv, bt709, progressive), 3840x2160 [SAR 1:1 DAR 16:9], 28001 kb/s, 59.91 fps, 60 tbr, 90k tbn (default)
    Metadata:
      creation_time   : 1970-01-01T00:00:02.000000Z
      handler_name    : VideoHandler
      vendor_id       : [0][0][0][0]
      encoder         : dailymotion/hls.js
Stream mapping:
  Stream #0:0 -> #0:0 (h264 (native) -> wrapped_avframe (native))
Press [q] to stop, [?] for help
Output #0, null, to '/dev/null':
  Metadata:
    compatible_brands: isomavc1
    minor_version   : 1
    major_brand     : isom
    encoder         : Lavf60.3.100
  Stream #0:0(und): Video: wrapped_avframe, nv12(tv, bt709, progressive), 3840x2160 [SAR 1:1 DAR 16:9], q=2-31, 200 kb/s, 60 fps, 60 tbn (default)
    Metadata:
      creation_time   : 1970-01-01T00:00:02.000000Z
      handler_name    : VideoHandler
      vendor_id       : [0][0][0][0]
      encoder         : Lavc60.3.100 wrapped_avframe
[h264 @ 0x139845c80] Frame num change from 59 to 020 bitrate=N/A speed= 1.9x     0x
[h264 @ 0x139845c80] decode_slice_header error
[h264 @ 0x1398051f0] vt decoder cb: output image buffer is null: -12909
[h264 @ 0x139845c80] hardware accelerator failed to decode picture
[h264 @ 0x1398051f0] vt decoder cb: output image buffer is null: -12909
[h264 @ 0x13984f090] hardware accelerator failed to decode picture
[h264 @ 0x1398051f0] vt decoder cb: output image buffer is null: -12909
[h264 @ 0x10950cf40] hardware accelerator failed to decode picture

And then that last part repeats a bunch. Full ffmpeg debug log if that's helpful. Remuxing the source m3u8 doesn't cause any issues at all:

ffmpeg -hwaccel videotoolbox -i problem.m3u8 -f null /dev/null
robwalch commented 1 year ago

Duplicated MOOV and SDTP atoms? What's in that TS?

iameli commented 1 year ago

@robwalch It's just these three files:

https://docs.livepeer.live/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/1660.ts
https://docs.livepeer.live/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/1661.ts
https://docs.livepeer.live/eli/966061CB-D79D-46A6-996C-699D87FD4D2D/hls-playback-problem/1662.ts

The only unusual thing I can think of there is that there are three tracks — H264, AAC, and Vorbis audio.

robwalch commented 1 year ago

The first and last segment play OK. Early in the playback (and decoding) of the second segment, is when the error occurs.

All three have the opus track. This should be ignored completely. There's a DVB stream type of 6 that HLS.js is ignoring.

I dumped the fmp4 output for the second segment and was able to play the audio and video files with QuickTime. No errors when run through ffprobe (5.1.1).

I can reproduce the pipeline error in Chrome:

Selected VDAVideoDecoder for video decoding, config: codec: h264, profile: h264 high, level: not available, alpha_mode: is_opaque, coded size: [3840,2160], visible rect: [0,0,3840,2160], natural size: [3840,2160], has extra data: false, encryption scheme: Unencrypted, rotation: 0°, flipped: 0, color space: {primaries:BT709, transfer:BT709, matrix:BT709, range:LIMITED}
Prepared video sample is not conformant
ISO-BMFF container metadata for video frame indicates that the frame is a keyframe, but the video frame contents indicate the opposite.
VDA Error 4
video decode error!
Error Group:
DecoderStatus
Error Code:
1
Stacktrace:
media/gpu/ipc/service/vda_video_decoder.cc:919
Error Group:
PipelineStatus
Error Code:
3
Stacktrace:
media/renderers/video_renderer_impl.cc:591
Caused by:
Error Group:
DecoderStatus
Error Code:
108
Stacktrace:
media/filters/decoder_stream.cc:192
robwalch commented 1 year ago

Here's the AVC mp4 which should be playable from 5-10s (0-5 and 10-15 empty):

https://github.com/video-dev/hls.js/assets/333258/26036a9b-80b6-46f1-935a-047d83cdda47

Let me know if there's an issue with the muxing of any of the samples or timestamps. I don't see the problem, but happy to work on a fix if someone can identify it in this example.

Thulinma commented 1 year ago

Huh... interesting! In that video, I'm noticing that the first second of data claims to contain 59 frames, and that the 60th frame is twice as long in duration as the others. When I look at the raw NAL units contained within, I'm counting a keyframe (nal unit type 5) followed by 59 non-keyframe slices (nal unit type 1) and then a keyframe again. Cross-referencing byte counts, it looks like the last frame of the first GOP was somehow "combined" with the second keyframe, which means that that second keyframe is actually two frames of data: the last non-keyframe followed by a keyframe. Since it's marked in the headers as being a keyframe but starts with a non-keyframe NAL unit, I bet that's the thing the decoder chokes on here.

EDIT: And I cross-referenced with the original TS data (to be clear, above is about the video in the message preceding this message) for the same time period, and that data does contain 60 distinct timestamps of equal length in the first GOP. So... yeah, something in the muxer is somehow combining that last frame of the GOP with the first frame of the next and considering it a single frame. Hopefully that's enough to figure out why it's happening?

robwalch commented 1 year ago

something in the muxer is somehow combining that last frame of the GOP with the first frame of the next and considering it a single frame. Hopefully that's enough to figure out why it's happening?

I can't image...

Using config:

{
  "debug": true,
  "enableWorker": false,
  "startPosition": 5,
  "maxMaxBufferLength": 3
}

load the sample stream in the description and break/step through remuxVideo: https://github.com/video-dev/hls.js/blob/70e2c34cabaee1eb7163e18a83a6184cbfb9737b/src/remux/mp4-remuxer.ts#L413

It's counting 299 input samples with 836 NAL units. Sample duration handled here and each sample has a duration of (1440 or 1530 / 90000):

https://github.com/video-dev/hls.js/blob/70e2c34cabaee1eb7163e18a83a6184cbfb9737b/src/remux/mp4-remuxer.ts#L585-L597

I don't see how frames would get combined by the remuxer. Maybe the issue is in tsdemuxer > avc-video-parser when parsing AVC NAL units:

https://github.com/video-dev/hls.js/blob/b84baee3d1c271b11b590ab36bd71ffd0af32ed7/src/demux/video/avc-video-parser.ts#L17

Thulinma commented 1 year ago

Yeah, this is almost certainly indeed a problem with the avc-video-parser... Note that the second GOP's first frame does not start with a AUD NAL unit, while every other frame in the TS data does. It seems the NVENC encoder occasionally neglects to insert an AUD before some keyframes, but otherwise always does it. The logic seems to assume AUDs are either always or never there, and that assumption does not hold for this stream. 🤔

When an AUD is seen, this logic happens before creating the new frame: https://github.com/video-dev/hls.js/blob/b84baee3d1c271b11b590ab36bd71ffd0af32ed7/src/demux/video/avc-video-parser.ts#L164-L166 But, when a AUD is missing, instead this logic happens, and the existing frame data is never pushed: https://github.com/video-dev/hls.js/blob/b84baee3d1c271b11b590ab36bd71ffd0af32ed7/src/demux/video/avc-video-parser.ts#L87 Copying those three lines over to here should resolve the issue, as in the presence of a keyframe you can safely assume any remaining frame data waiting to be pushed belongs to a separate frame. On that note, there's another case that should probably also use this logic, when a type-1 NAL unit is a keyframe, here: https://github.com/video-dev/hls.js/blob/b84baee3d1c271b11b590ab36bd71ffd0af32ed7/src/demux/video/avc-video-parser.ts#L79 (does not apply to this stream specifically, but the same thing could happen here for a theoretical other stream)

Thulinma commented 1 year ago

Went ahead and made a PR for my suggested solution. 👍

iameli commented 1 year ago

Confirmed that @Thulinma's branch fixes the problem for me! Here's a built version of the player that plays back smoothly.

EDIT: Published to npm as @iameli/hls.js@1.4.8-190-g84002fb8

robwalch commented 1 year ago

Thanks for the bug report and the fix. Changes are available in dev and in v1.4.9:

https://github.com/video-dev/hls.js/releases/tag/v1.4.9