VideoToolbox VP9 hwaccel freezes ffmpeg

[Eric Karnes]

Summary of the bug:

When testing the new videotoolbox VP9 decoder support I ran into an issue on my machine where ffmpeg freezes.

ffmpeg doesn't respond to [q] or ? however I'm able to hard exit.

I'm using a 2017 iMac, imac18,3.

The input is a VP9 YouTube video, I've observed this issue with every VP9 YouTube video I've tried.

How to reproduce:

% ffmpeg -v 9 -loglevel 99 -hwaccel videotoolbox -threads 1 -i /Users/eric/Downloads/test.webm -f null - -benchmark -report
ffmpeg version N-105288-g45e45a6060
built on 01/15/2022

Here is my output

ffmpeg started on 2022-01-15 at 15:34:58
Report written to "ffmpeg-20220115-153458.log"
Log level: 99
Command line:
./ffmpeg -v 9 -loglevel 99 -hwaccel videotoolbox -threads 1 -i /Users/eric/Downloads/test.webm -f null - -benchmark -report
ffmpeg version N-105288-g45e45a6060 Copyright (c) 2000-2022 the FFmpeg developers
  built with Apple clang version 13.0.0 (clang-1300.0.29.30)
  configuration: --enable-gpl --enable-libaom --enable-libdav1d --enable-libmp3lame --enable-libopus --enable-libsnappy --enable-libtheora --enable-libvmaf --enable-libvorbis --enable-libvpx --enable-libx264 --enable-libx265 --enable-libfontconfig --enable-libfreetype --enable-frei0r --enable-libass --enable-demuxer=dash --enable-opencl --enable-videotoolbox --disable-htmlpages --enable-libfdk-aac --enable-librav1e --enable-librubberband --enable-libspeex --enable-libwebp --enable-nonfree
  libavutil      57. 18.100 / 57. 18.100
  libavcodec     59. 20.100 / 59. 20.100
  libavformat    59. 17.101 / 59. 17.101
  libavdevice    59.  5.100 / 59.  5.100
  libavfilter     8. 25.100 /  8. 25.100
  libswscale      6.  5.100 /  6.  5.100
  libswresample   4.  4.100 /  4.  4.100
  libpostproc    56.  4.100 / 56.  4.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-hwaccel' ... matched as option 'hwaccel' (use HW accelerated decoding) with argument 'videotoolbox'.
Reading option '-threads' ... matched as AVOption 'threads' with argument '1'.
Reading option '-i' ... matched as input url with argument '/Users/eric/Downloads/test.webm'.
Reading option '-f' ... matched as option 'f' (force format) with argument 'null'.
Reading option '-' ... matched as output url.
Reading option '-benchmark' ... matched as option 'benchmark' (add timings for benchmarking) with argument '1'.
Reading option '-report' ... matched as option 'report' (generate a report) with argument '1'.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Applying option loglevel (set logging level) with argument 99.
Applying option benchmark (add timings for benchmarking) with argument 1.
Applying option report (generate a report) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input url /Users/eric/Downloads/test.webm.
Applying option hwaccel (use HW accelerated decoding) with argument videotoolbox.
Successfully parsed a group of options.
Opening an input file: /Users/eric/Downloads/test.webm.
[NULL @ 0x7faf14704100] Opening '/Users/eric/Downloads/test.webm' for reading
[file @ 0x7faf247046c0] Setting default whitelist 'file,crypto,data'
Probing matroska,webm score:100 size:2048
[matroska,webm @ 0x7faf14704100] Format matroska,webm probed with size=2048 and score=100
st:0 removing common factor 1000000 from timebase
st:1 removing common factor 1000000 from timebase
[matroska,webm @ 0x7faf14704100] Before avformat_find_stream_info() pos: 636 bytes read:32768 seeks:0 nb_streams:2
[vp9 @ 0x7faf24705580] Format yuv420p chosen by get_format().
[opus @ 0x7faf24705e80] skip 312/960 samples
[matroska,webm @ 0x7faf14704100] All info found
[matroska,webm @ 0x7faf14704100] stream 0: start_time: 0 duration: NOPTS
[matroska,webm @ 0x7faf14704100] stream 1: start_time: -0.007 duration: NOPTS
[matroska,webm @ 0x7faf14704100] format: start_time: -0.007 duration: 15.021 (estimate from stream) bitrate=1336 kb/s
[matroska,webm @ 0x7faf14704100] After avformat_find_stream_info() pos: 1483 bytes read:32768 seeks:0 frames:2
Input #0, matroska,webm, from '/Users/eric/Downloads/test.webm':
  Metadata:
    ENCODER         : Lavf58.76.100
  Duration: 00:00:15.02, start: -0.007000, bitrate: 1336 kb/s
  Stream #0:0(eng), 1, 1/1000: Video: vp9 (Profile 0), 1 reference frame, yuv420p(tv, bt709), 720x1280, 0/1, SAR 1:1 DAR 9:16, 30 fps, 30 tbr, 1k tbn (default)
    Metadata:
      DURATION        : 00:00:14.999000000
  Stream #0:1(eng), 1, 1/1000: Audio: opus, 48000 Hz, stereo, fltp, delay 312 (default)
    Metadata:
      DURATION        : 00:00:15.021000000
Successfully opened the file.
Parsing a group of options: output url -.
Applying option f (force format) with argument null.
Successfully parsed a group of options.
Opening an output file: -.
Successfully opened the file.
Stream mapping:
  Stream #0:0 -> #0:0 (vp9 (native) -> wrapped_avframe (native))
  Stream #0:1 -> #0:1 (opus (native) -> pcm_s16le (native))
Press [q] to stop, [?] for help
cur_dts is invalid st:0 (0) [init:0 i_done:0 finish:0] (this is harmless if it occurs once at the start per stream)
[vp9 @ 0x7faf04704100] Format videotoolbox_vld chosen by get_format().
[vp9 @ 0x7faf04704100] Format videotoolbox_vld requires hwaccel initialisation.
detected 8 logical cores
[graph 0 input from stream 0:0 @ 0x7faf24723e40] Setting 'video_size' to value '720x1280'
[graph 0 input from stream 0:0 @ 0x7faf24723e40] Setting 'pix_fmt' to value '23'
[graph 0 input from stream 0:0 @ 0x7faf24723e40] Setting 'time_base' to value '1/1000'
[graph 0 input from stream 0:0 @ 0x7faf24723e40] Setting 'pixel_aspect' to value '1/1'
[graph 0 input from stream 0:0 @ 0x7faf24723e40] Setting 'frame_rate' to value '30/1'
[graph 0 input from stream 0:0 @ 0x7faf24723e40] w:720 h:1280 pixfmt:nv12 tb:1/1000 fr:30/1 sar:1/1
[AVFilterGraph @ 0x7faf247198c0] query_formats: 3 queried, 2 merged, 0 already done, 0 delayed
cur_dts is invalid st:0 (0) [init:1 i_done:0 finish:0] (this is harmless if it occurs once at the start per stream)
cur_dts is invalid st:1 (0) [init:0 i_done:0 finish:0] (this is harmless if it occurs once at the start per stream)
[opus @ 0x7faf04704980] skip 312/960 samples
[graph_1_in_0_1 @ 0x7faf247258c0] Setting 'time_base' to value '1/48000'
[graph_1_in_0_1 @ 0x7faf247258c0] Setting 'sample_rate' to value '48000'
[graph_1_in_0_1 @ 0x7faf247258c0] Setting 'sample_fmt' to value 'fltp'
[graph_1_in_0_1 @ 0x7faf247258c0] Setting 'channel_layout' to value '0x3'
[graph_1_in_0_1 @ 0x7faf247258c0] tb:1/48000 samplefmt:fltp samplerate:48000 chlayout:0x3
[format_out_0_1 @ 0x7faf24725e80] Setting 'sample_fmts' to value 's16'
[format_out_0_1 @ 0x7faf24725e80] auto-inserting filter 'auto_aresample_0' between the filter 'Parsed_anull_0' and the filter 'format_out_0_1'
[AVFilterGraph @ 0x7faf247253c0] query_formats: 4 queried, 6 merged, 3 already done, 0 delayed
[auto_aresample_0 @ 0x7faf24726540] [SWR @ 0x7faef8050000] Using fltp internally between filters
[auto_aresample_0 @ 0x7faf24726540] ch:2 chl:stereo fmt:fltp r:48000Hz -> ch:2 chl:stereo fmt:s16 r:48000Hz
Output #0, null, to 'pipe:':
  Metadata:
    encoder         : Lavf59.17.101
  Stream #0:0(eng), 0, 1/30: Video: wrapped_avframe, 1 reference frame, nv12(tv, bt709, progressive), 720x1280 (0x0) [SAR 1:1 DAR 9:16], 0/1, q=2-31, 200 kb/s, 30 fps, 30 tbn (default)
    Metadata:
      DURATION        : 00:00:14.999000000
      encoder         : Lavc59.20.100 wrapped_avframe
  Stream #0:1(eng), 0, 1/48000: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s (default)
    Metadata:
      DURATION        : 00:00:15.021000000
      encoder         : Lavc59.20.100 pcm_s16le
frame=    1 fps=0.0 q=-0.0 size=N/A time=00:00:00.03 bitrate=N/A speed=0.383x    

[Peter Xia]

I'm able to reproduce this. It's working on my apple silicon mac but freezing on my intel one.

[Eric Karnes]

Replying to Peter Xia:

I'm able to reproduce this. It's working on my apple silicon mac but freezing on my intel one.

What model Mac are you able to reproduce this with? I'm trying to figure out if this is an issue with all Intel Macs with VP9 decode support or specifically ones that use the Intel iGPU for VP9 decode.

[WindowPain]

I'm having the same problem. My machine is 2017 MacBook Pro.

[Eric Karnes]

Bug is still present on macOS 13.0 Beta

[Eric Karnes]

I've since updated to FFMPEG 6.0 and am using Ventura 13.4 and the bug is still present however I'm given more information in the logs

[vp9 @ 0x7f84cf704080] Format videotoolbox_vld chosen by get_format().
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld requires hwaccel initialisation.
[vp9 @ 0x7f84cf704080] Unknown VideoToolbox session creation error -12907
[vp9 @ 0x7f84cf704080] Failed setup for format videotoolbox_vld: hwaccel initialisation returned error.
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld not usable, retrying get_format() without it.
[vp9 @ 0x7f84cf704080] Format yuv420p chosen by get_format().

error -12907 seems to correlate to "kVTCouldNotCreateInstanceErr" while my Mac's console gives the error

[VP9] GVA error: ailed to create context

[Balling]

ailed?

[Eric Karnes]

Replying to Balling:

ailed?

I would assume it's meant to be failed but that's the message it always gives.

[Balling]

but that's the message it always gives.

So that is some typo in MacOS system libraries or driver?

[Eric Karnes]

Replying to Balling:

but that's the message it always gives.

So that is some typo in MacOS system libraries or driver?

It would seem so yes.

[quinkblack]

Replying to Eric Karnes:

I've since updated to FFMPEG 6.0 and am using Ventura 13.4 and the bug is still present however I'm given more information in the logs

[vp9 @ 0x7f84cf704080] Format videotoolbox_vld chosen by get_format().
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld requires hwaccel initialisation.
[vp9 @ 0x7f84cf704080] Unknown VideoToolbox session creation error -12907
[vp9 @ 0x7f84cf704080] Failed setup for format videotoolbox_vld: hwaccel initialisation returned error.
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld not usable, retrying get_format() without it.
[vp9 @ 0x7f84cf704080] Format yuv420p chosen by get_format().

error -12907 seems to correlate to "kVTCouldNotCreateInstanceErr" while my Mac's console gives the error

[VP9] GVA error: ailed to create context

The hardware or OS doesn't support VP9 decoding. FFmpeg should be able to switch to software decoding.

Please reopen the ticket if there is other issue with FFmpeg master branch.

[Eric Karnes]

Replying to quinkblack:

Replying to Eric Karnes:

I've since updated to FFMPEG 6.0 and am using Ventura 13.4 and the bug is still present however I'm given more information in the logs

[vp9 @ 0x7f84cf704080] Format videotoolbox_vld chosen by get_format().
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld requires hwaccel initialisation.
[vp9 @ 0x7f84cf704080] Unknown VideoToolbox session creation error -12907
[vp9 @ 0x7f84cf704080] Failed setup for format videotoolbox_vld: hwaccel initialisation returned error.
[vp9 @ 0x7f84cf704080] Format videotoolbox_vld not usable, retrying get_format() without it.
[vp9 @ 0x7f84cf704080] Format yuv420p chosen by get_format().

error -12907 seems to correlate to "kVTCouldNotCreateInstanceErr" while my Mac's console gives the error

[VP9] GVA error: ailed to create context

The hardware or OS doesn't support VP9 decoding. FFmpeg should be able to switch to software decoding.

Please reopen the ticket if there is other issue with FFmpeg master branch.

Thanks for the clarification, it seems that when I have my eGPU plugged in it takes over for decoding and that doesn't actually support VP9 so that explains why my logs were different. If I unplug my eGPU so that only my iGPU which supports VP9 is used, then it goes back to minimal logs and freezing. I've verified this on the master branch.

[Eric Karnes]

I've gone through and enabled some trace output for CoreMedia which gives me the following logs while reproducing this issue.

<<<< VT-DS >>>> vtDecompressionDuctCreate: decoder requested VideoToolbox handle QualityOfService
<<<< VT-DS >>>> vtDecompressionDuctCreate: DecoderType: Hardware
<<<< MemoryPool >>>> CMMemoryPoolCreate: pool 0x60000083a840 created vending allocator 0x600003328680
<<<< PixelBufferSharing >>>> pixelBufferRecipient_createRecipientPixelBuffer: created pixel buffer from components. Saved backing 0x7fd2b180b200 (ID 548)
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< PixelBufferSharing >>>> pixelBufferRecipient_createRecipientPixelBuffer: created pixel buffer from components. Saved backing 0x7fd2e001a800 (ID 552)
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< PixelBufferSharing >>>> pixelBufferRecipient_createRecipientPixelBuffer: created pixel buffer from components. Saved backing 0x7fd2e801f400 (ID 554)
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]
<<<< RemoteDecode - client >>>> RemoteVideoDecoder_DecodeFrame: 1 frames still pending after synchronous decode
<<<< VT-DS >>>> vtDecompressionDuctDecodeSingleFrame: (0x600003927660) frame 0xb still pending after synchronous immediate DecodeFrame call
<<<< VT-DS >>>> VTDecompressionSessionWaitForAsynchronousFrames: [session: 0x600003927660]
<<<< VT-DS >>>> VTDecompressionSessionFinishDelayedFrames: [session: 0x600003927660]

I would assume the most important bits would be,

<<<< RemoteDecode - client >>>> RemoteVideoDecoder_DecodeFrame: 1 frames still pending after synchronous decode
<<<< VT-DS >>>> vtDecompressionDuctDecodeSingleFrame: (0x600003927660) frame 0xb still pending after synchronous immediate DecodeFrame call

considering they show up as errors in the console.

[Eric Karnes]

Output of 'sample' from the frozen ffmpeg process

[Eric Karnes]

I've reverified that the master branch is affected by this issue and attached the output from sample for the frozen ffmpeg process.

[Eric Karnes]

I've grabbed a backtrace of the freeze using lldb

(lldb) thread info -s
thread #1: tid = 0x5c4f8, 0x00007ff81a0d08ec libsystem_pthread.dylib`_pthread_cond_updateval + 1, queue = 'com.apple.main-thread', stop reason = instruction step into

(lldb) thread list
Process 40009 stopped
* thread #1: tid = 0x5c4f8, 0x00007ff81a0d08ec libsystem_pthread.dylib`_pthread_cond_updateval + 1, queue = 'com.apple.main-thread', stop reason = instruction step into
  thread #2: tid = 0x5c4fc, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #3: tid = 0x5c4fd, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #4: tid = 0x5c4ff, 0x00007ff81a095162 libsystem_kernel.dylib`__workq_kernreturn + 10
  thread #5: tid = 0x5c50a, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #6: tid = 0x5c50b, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #7: tid = 0x5c50c, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #8: tid = 0x5c50d, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #9: tid = 0x5c50e, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #10: tid = 0x5c50f, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #11: tid = 0x5c510, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #12: tid = 0x5c511, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #13: tid = 0x5c512, 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10

(lldb) bt all
* thread #1, queue = 'com.apple.main-thread', stop reason = instruction step into
  * frame #0: 0x00007ff81a0d08ec libsystem_pthread.dylib`_pthread_cond_updateval + 1
    frame #1: 0x00007ff81a0d37df libsystem_pthread.dylib`_pthread_cond_wait + 1327
    frame #2: 0x000000010aef9f6b ffmpeg_g`tq_receive(tq=0x0000611000003b00, stream_idx=0x00007ff7b50c96e0, data=0x0000616000005180) at thread_queue.c:202:13
    frame #3: 0x000000010ae39078 ffmpeg_g`dec_packet(ist=0x0000614000000440, pkt=0x0000610000010340, no_eof=0) at ffmpeg_dec.c:791:15
    frame #4: 0x000000010af1a86a ffmpeg_g`process_input_packet(ist=0x0000614000000440, pkt=0x0000610000010340, no_eof=0) at ffmpeg.c:820:15
    frame #5: 0x000000010af1c0ad ffmpeg_g`process_input(file_index=0) at ffmpeg.c:1144:11
    frame #6: 0x000000010af18ac3 ffmpeg_g`transcode_step(ost=0x0000617000000780) at ffmpeg.c:1171:11
    frame #7: 0x000000010af154a2 ffmpeg_g`transcode(err_rate_exceeded=0x00007ff7b50ca0c0) at ffmpeg.c:1232:15
    frame #8: 0x000000010af14d9a ffmpeg_g`main(argc=15, argv=0x00007ff7b50ca4e0) at ffmpeg.c:1358:11
    frame #9: 0x00007ff819d4a3a6 dyld`start + 1942
  thread #2
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x00007ff8247741c1 CoreMedia`WaitOnConditionTimed + 82
    frame #3: 0x00007ff82475620d CoreMedia`FigSemaphoreWaitRelative + 161
    frame #4: 0x00007ff8291c9701 VideoToolbox`VTDecompressionSessionWaitForAsynchronousFrames + 708
    frame #5: 0x000000010ea63577 ffmpeg_g`videotoolbox_session_decode_frame(avctx=0x0000619000026780) at videotoolbox.c:729:18
    frame #6: 0x000000010ea61d0c ffmpeg_g`ff_videotoolbox_common_end_frame(avctx=0x0000619000026780, frame=0x0000616000005780) at videotoolbox.c:1021:14
    frame #7: 0x000000010ea6af13 ffmpeg_g`videotoolbox_vp9_end_frame(avctx=0x0000619000026780) at videotoolbox_vp9.c:125:12
    frame #8: 0x000000010ed05998 ffmpeg_g`vp9_decode_frame(avctx=0x0000619000026780, frame=0x0000616000005480, got_frame=0x0000700001f5d360, pkt=0x0000610000002a40) at vp9.c:1648:15
    frame #9: 0x000000010d02eb34 ffmpeg_g`decode_simple_internal(avctx=0x0000619000026780, frame=0x0000616000005480, discarded_samples=0x0000700001f5d3e0) at decode.c:431:20
    frame #10: 0x000000010d02e00b ffmpeg_g`decode_simple_receive_frame(avctx=0x0000619000026780, frame=0x0000616000005480) at decode.c:605:15
    frame #11: 0x000000010d01ab09 ffmpeg_g`decode_receive_frame_internal(avctx=0x0000619000026780, frame=0x0000616000005480) at decode.c:633:15
    frame #12: 0x000000010d01a552 ffmpeg_g`avcodec_send_packet(avctx=0x0000619000026780, avpkt=0x0000610000008040) at decode.c:730:15
    frame #13: 0x000000010ae3ed84 ffmpeg_g`packet_decode(ist=0x0000614000000440, pkt=0x0000610000008040, frame=0x000061600000ff80) at ffmpeg_dec.c:555:11
    frame #14: 0x000000010ae3db3b ffmpeg_g`decoder_thread(arg=0x0000614000000440) at ffmpeg_dec.c:702:15
    frame #15: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #16: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #3
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa744f8 ffmpeg_g`av_thread_message_queue_send_locked(mq=0x0000611000003c40, msg=0x0000700001fe0c80, flags=0) at threadmessage.c:129:9
    frame #3: 0x000000010fa743e0 ffmpeg_g`av_thread_message_queue_send(mq=0x0000611000003c40, msg=0x0000700001fe0c80, flags=0) at threadmessage.c:166:11
    frame #4: 0x000000010ae5b473 ffmpeg_g`input_thread(arg=0x0000612000000640) at ffmpeg_demux.c:650:15
    frame #5: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #6: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #4
    frame #0: 0x00007ff81a095162 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x00007ff81a0cfca0 libsystem_pthread.dylib`_pthread_wqthread + 416
    frame #2: 0x00007ff81a0ceb97 libsystem_pthread.dylib`start_wqthread + 15
  thread #5
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028a80) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #6
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028b08) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #7
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028b90) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #8
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028c18) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #9
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028ca0) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #10
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028d28) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #11
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028db0) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #12
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010fa716a3 ffmpeg_g`thread_worker(v=0x0000619000028e38) at slicethread.c:82:13
    frame #3: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #4: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15
  thread #13
    frame #0: 0x00007ff81a0965e6 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff81a0d376b libsystem_pthread.dylib`_pthread_cond_wait + 1211
    frame #2: 0x000000010aef9f6b ffmpeg_g`tq_receive(tq=0x00006110000043c0, stream_idx=0x0000700002687e40, data=0x0000610000030040) at thread_queue.c:202:13
    frame #3: 0x000000010aea3d62 ffmpeg_g`muxer_thread(arg=0x0000611000002fc0) at ffmpeg_mux.c:215:15
    frame #4: 0x00007ff81a0d3202 libsystem_pthread.dylib`_pthread_start + 99
    frame #5: 0x00007ff81a0cebab libsystem_pthread.dylib`thread_start + 15

[low-batt]

Note that there are two problems here, the failure to decode the frame and the severe problem with permanently blocking the thread, preventing a fallback to software decoding.

Does FFmpeg have any Apple contacts? I've investigated this a bit and I'm not seeing a good way for FFmpeg to workaround Apple's bad error handling. See below for more details.

This problem is important as the ​mpv project added VP9 to the default value of its white-list of codecs that are considered safe to use with hardware decoding: ​hwdec-codecs

The ​IINA project was tripped up by this after upgrading mpv and FFmpeg and had to quickly issue a new release with a workaround to disable VP9 hardware decode on Intel Macs. See IINA issue ​#4486.

The open VLC issue ​27874 references this FFmpeg ticket. That issue also references the closed Chromium issue ​1115334. The Chromium issue contains this interesting post (from 2020):

After discussion with Apple this is due to the fact that they require VP9 alt-ref frames to be packaged as superframes. I've written some code to do this. On their side, they expect to make it an error when alt-ref frames are sent unpacked.

As that was back in 2020 the error handling must have been updated by now, right Apple? And if ​Video Toolbox has this restriction why in the case at hand is hardware decoding working under Apple Silicon? My development machine is a MacBookPro18,2 with a M1 Max processor under macOS 13.5 and the problem does not reproduce on that Mac.

In order to investigate this I purchased a reconditioned MacBookPro16,1 with a 6-Core Intel Core i7 processor. On that Mac using the file ​buck-1280x720-vp9.webm from the above mentioned Chromium issue FFmpeg hangs:

low-batt@urp ffmpeg (master *%=)$ ffmpeg -hide_banner -hwaccel videotoolbox -i buck-1280x720-vp9.webm -f null -
Input #0, matroska,webm, from 'buck-1280x720-vp9.webm':
  Metadata:
    encoder         : libwebm-0.2.1.0
  Duration: 00:00:00.17, start: 0.000000, bitrate: 856 kb/s
  Stream #0:0(eng): Video: vp9 (Profile 0), yuv420p(tv), 1280x720, SAR 1:1 DAR 16:9, 29.92 fps, 29.92 tbr, 1k tbn (default)
Stream mapping:
  Stream #0:0 -> #0:0 (vp9 (native) -> wrapped_avframe (native))
Press [q] to stop, [?] for help
^C^C^CReceived > 3 system signals, hard exiting

FFmpeg is hanging in the method videotoolbox_session_decode_frame at the call to ​VTDecompressionSessionWaitForAsynchronousFrames in this code:

    status = VTDecompressionSessionDecodeFrame(videotoolbox->session,
                                               sample_buf,
                                               0,       // decodeFlags
                                               NULL,    // sourceFrameRefCon
                                               0);      // infoFlagsOut
    if (status == noErr)
        status = VTDecompressionSessionWaitForAsynchronousFrames(videotoolbox->session);

This code seems odd to me because the Apple documentation for ​VTDecompressionSessionDecodeFrame(\_:sampleBuffer:flags:frameRefcon:infoFlagsOut:) says:

decodeFlags
A bitfield of directives to the decompression session and decoder.

The ​kVTDecodeFrame_EnableAsynchronousDecompression bit indicates whether the video decoder may decompress the frame asynchronously.

The ​kVTDecodeFrame_EnableTemporalProcessing bit indicates whether the decoder may delay calls to the output callback so as to enable processing in temporal (display) order.

If both flags are clear, the decompression completes and your output callback function will be called before VTDecompressionSessionDecodeFrame returns.

For the decodeFlags parameter the above code passes 0, requesting synchronous processing. Given that, why is FFmpeg calling VTDecompressionSessionWaitForAsynchronousFrames?

A quick test on my M1 Mac with that call commented out it seemed like decoding worked. On the Intel Mac FFmpeg quickly froze in videotoolbox_stop on the call to ​VTDecompressionSessionInvalidate:

    + 2348 ff_videotoolbox_common_end_frame  (in ffmpeg) + 191  [0x10128255f]
    +   2348 VTDecompressionSessionInvalidate  (in VideoToolbox) + 83  [0x7ff815d41a79]
    +     2347 ???  (in VideoToolbox)  load address 0x7ff815d38000 + 0x28c356  [0x7ff815fc4356]
    +     ! 2347 FigSemaphoreWaitRelative  (in CoreMedia) + 152  [0x7ff8110fb066]
    +     !   2347 WaitOnConditionTimed  (in CoreMedia) + 78  [0x7ff81110e3ff]
    +     !     2347 _pthread_cond_wait  (in libsystem_pthread.dylib) + 1242  [0x7ff80783d758]
    +     !       2347 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7ff8078010fe]

With the call to VTDecompressionSessionInvalidate commented out, FFmpeg froze on the following call to ​CFRelease which itself called VTDecompressionSessionInvalidate.

Adding some print statements shows the first frame is decoded successfully. But the second call to VTDecompressionSessionDecodeFrame returns without calling videotoolbox_decoder_callback. Based on that behavior it seems there was a failure trying to decode the second frame and yet VTDecompressionSessionDecodeFrame returned a successful OSStatus. It also seems it did so without having signaled the internal semaphore that indicates VTDecompressionSessionDecodeFrame is in progress.

If FFmpeg wanted to continue to use VTDecompressionSessionWaitForAsynchronousFrames it could detect that no frame was generated and assume VTDecompressionSessionDecodeFrame failed even though it returned success. But with the method VTDecompressionSessionInvalidate also hanging I don't see how FFmpeg can workaround the mismanagement of the semaphore by Video Toolbox.

Hopefully somebody has a contact at Apple that can explain why the error handing in VTDecompressionSessionDecodeFrame is so badly broken and why decoding is working fine under Apple Silicon.

This is what the output of that test looked like:

low-batt@urp ffmpeg (master *%=)$ ./ffmpeg -hide_banner -hwaccel videotoolbox -i buck-1280x720-vp9.webm -f null -
Input #0, matroska,webm, from 'buck-1280x720-vp9.webm':
  Metadata:
    encoder         : libwebm-0.2.1.0
  Duration: 00:00:00.17, start: 0.000000, bitrate: 856 kb/s
  Stream #0:0(eng): Video: vp9 (Profile 0), yuv420p(tv), 1280x720, SAR 1:1 DAR 16:9, 29.92 fps, 29.92 tbr, 1k tbn (default)
Stream mapping:
  Stream #0:0 -> #0:0 (vp9 (native) -> wrapped_avframe (native))
Press [q] to stop, [?] for help
Calling VTDecompressionSessionDecodeFrame
In videotoolbox_decoder_callback OSStatus is: 0
Returned from VTDecompressionSessionDecodeFrame OSStatus is: 0
Calling VTDecompressionSessionWaitForAsynchronousFrames
Calling VTDecompressionSessionDecodeFrame
Returned from VTDecompressionSessionDecodeFrame OSStatus is: 0
Calling VTDecompressionSessionWaitForAsynchronousFrames

[FreezyLemon]

The osu-framework is another project that is affected by this, and is ​waiting for a fix or workaround before upgrading its ffmpeg libraries.

Thanks to low-batts extensive information, I have an idea on a possible workaround on the consumer end. Looking at the chromium issue, ​this is how they fixed the issue:

This assembles superframes from vp9 alt ref frames since that's what the macOS VP9 decoder is expecting.

More specifically, they use a bitstream filter (BSF) to modify the encoded bitstream before sending it to the HW decoder. I noticed that the ffmpeg libraries also include a bitstream filter called vp9_superframe that seems to do the exact same thing, though I haven't looked at the implementation to confirm this.

I do not have any Apple hardware, so I cannot confirm whether this workaround works. But the idea would be to change from this:

ffmpeg -hide_banner -hwaccel videotoolbox -i test.webm -f null -

to this:

ffmpeg -hide_banner -i test.webm -c:v copy -bsf:v vp9_superframe -f webm - | ffmpeg -hide_banner -f webm -hwaccel videotoolbox -i pipe: -f null -

Something like this should also be doable through libavcodec (BSFs, though named "filters", are part of avcodec, not avfilter), but again, I can't try this myself. I'd appreciate if someone could test this, as it would be a relatively simple workaround.

[Eric Karnes]

Replying to FreezyLemon:

The osu-framework is another project that is affected by this, and is ​waiting for a fix or workaround before upgrading its ffmpeg libraries.

Thanks to low-batts extensive information, I have an idea on a possible workaround on the consumer end. Looking at the chromium issue, ​this is how they fixed the issue:

This assembles superframes from vp9 alt ref frames since that's what the macOS VP9 decoder is expecting.

More specifically, they use a bitstream filter (BSF) to modify the encoded bitstream before sending it to the HW decoder. I noticed that the ffmpeg libraries also include a bitstream filter called vp9_superframe that seems to do the exact same thing, though I haven't looked at the implementation to confirm this.

I do not have any Apple hardware, so I cannot confirm whether this workaround works. But the idea would be to change from this:

ffmpeg -hide_banner -hwaccel videotoolbox -i test.webm -f null -

to this:

ffmpeg -hide_banner -i test.webm -c:v copy -bsf:v vp9_superframe -f webm - | ffmpeg -hide_banner -f webm -hwaccel videotoolbox -i pipe: -f null -

Something like this should also be doable through libavcodec (BSFs, though named "filters", are part of avcodec, not avfilter), but again, I can't try this myself. I'd appreciate if someone could test this, as it would be a relatively simple workaround.

I attempted your workaround on master and unfortunately it still locks up the same as it would otherwise.

[FreezyLemon]

Replying to Eric Karnes:

I attempted your workaround on master and unfortunately it still locks up the same as it would otherwise.

That is unfortunate. I checked the code and discovered that the BSF "vp9_superframe_split" is defined to be run in vp9.c:

    .bsfs                  = "vp9_superframe_split",

This BSF does the opposite/reverse of vp9_superframe, namely splitting superframes into singular frames (this is apparently needed for the software decoder). So the work done by "vp9_superframe" is being undone right before decoding.

Not sure if there's a simple way to disable this for just videotoolbox. Removing this altogether would most likely break other decoders...

[low-batt]

As a very quick hacky test, this change to vp9.c:

-    .bsfs                  = "vp9_superframe_split",
+    .bsfs                  = "vp9_superframe",

Caused FFmpeg to be able to decode the example video from the Chromium bug as well as a longer video that showed the problem.

This is more evidence suggesting:

• Apple never fixed Video Toolbox error handling dispite having said they were going to causing problems for people all over the entire planet
• The Video Toolbox implementation for Apple Silicon does not impose the requirement to package alt-ref frames as superframes
• Apple never updated the Intel Video Toolbox implementation to match the Apple Silicon behavior

Late here and I am incoherent. I should have time to look into this some more tomorrow.

[low-batt]

Patch that adds a separate VP9 Video Toolbox decoder.

[low-batt]

A patch file should be attached. The changes create a separate decoder for VP9 decoding with Video Toolbox. That decoder uses vp9_superframe instead of vp9_superframe_split on Intel Macs.

I think this is how to change the BSF filter only when hardware decoding is enabled. What I'm not clear on is how FFmpeg decides not to use this decoder when software decoding. Really need a FFmpeg developer for this.

I built a libavcodec.dylib with these changes and tested it with ​IINA on my Intel Mac. The longer test video played fine with hardware decoding. This is what the ​mpv log showed:

[  22.665][v][vd] Codec list:
[  22.665][v][vd]     vp9 - Google VP9
[  22.665][v][vd]     vp9_videotoolbox (vp9) - VideoToolbox Google VP9
[  22.665][v][vd] Opening decoder vp9
[  22.665][v][vd] Looking at hwdec vp9_videotoolbox-videotoolbox...
[  22.665][v][vd] Trying hardware decoding via vp9_videotoolbox-videotoolbox.
[  22.665][v][vd] Using underlying hw-decoder 'vp9_videotoolbox'
[  22.665][v][vd] Selected codec: vp9 (Google VP9)
…
[  22.786][i][vd] Using hardware decoding (videotoolbox).

I also tested disabling hardware decoding, which also played fine:

[   3.990][v][vd] Codec list:
[   3.990][v][vd]     vp9 - Google VP9
[   3.990][v][vd]     vp9_videotoolbox (vp9) - VideoToolbox Google VP9
[   3.990][v][vd] Opening decoder vp9
[   3.990][v][vd] No hardware decoding requested.
[   3.990][v][vd] Using software decoding.
[   3.990][v][vd] Detected 12 logical cores.
[   3.990][v][vd] Requesting 13 threads for decoding.
[   3.991][v][vd] Selected codec: vp9 (Google VP9)

[FreezyLemon]

Nice. Good to know that this can be worked around. I assume that forcing decoding via vp9_videotoolbox without hwaccel would result in a crash, or corrupted output? That would make this workaround risky to use... Maybe there's a way to define a codec as "HW accelerated only", meaning it doesn't provide software decoding at all?

EDIT: For what it's worth, the CUVID decoders do something like this. They don't use the -hwaccel option to enable the hardware decoder (it does something else for cuvid). Choosing the h264_cuvid decoder, for example, will enable hardware decoding. It looks like enabling the AV_CODEC_CAP_HARDWARE flag in AVCodec->capabilities is what enables this behaviour. I'm not sure this is applicable here though, since some things are definitely different about the CUVID decoder implementations.

[low-batt]

As I have never dug into FFmpeg sources I have the same questions you raised. I plan on getting back to reading FFmpeg sources and testing to see what else needs to be done to fix this properly soon. I'm juggling a number of tasks at the moment.

[ePirat]

Indeed this hang in Videotoolbox can be worked around with the vp9_superframe bsf, I am currently investigating ways to make this work for VT without breaking the rest…

After some IRC discussion, given that VT expects packets not slices, one option would be to make VT its own codec, but downsides of this would be lack of software fallback and metadata propagation, which right now is parsed by the VP9 decoder IIUC.

[low-batt]

In general the software fallback is a very important feature. Although things have improved there are still problems with hardware decoding. The automatic fallback to software decoding stops these problems from being a show stopper for users that don't understand hardware vs. software decoding and how to turn off hardware decoding.

In this particular case, because the defect in Video Toolbox prevented FFmpeg from falling back to software decoding ​IINA had to put out a release to disable VP9 hardware decoding for Intel Macs.

Thus a fix that does not allow for software fallback is concerning.

Thank you very much for looking into this problem. Users had been wanting VP9 hardware decoding and are disappointed that it is not working.