Handbrake starting encode, then immediately completing encode with 0kb output

[Aerochill]

Current Behavior

I am using Handbrake with autovideoconverter. When I try to use the watch folder with autovideoencoder the process just ends up like I stated in the title.

Doing so through the Handbrake GUI, however, yields expected results. I've combed through the logs and I can't seem to figure out why it is "succeeding" to encode nothing.

Expected Behavior

Autovideoconerter should behave the same as the GUI.

Steps To Reproduce

I simply used my custom preset and set the watch folder to download like I have many times before.

Environment

• OS: TrueNAS
• OS version: Scale 24.04
• CPU: AMD Ryzen 5 5600
• Docker version: 24.03.1
• Device model:
• Browser/OS: Opera GX on other machine

Container creation

TrueCharts implementation

Container log

2024-04-24 09:05:12.847891-07:00[autovideoconverter] Change detected in watch folder '/watch'.
2024-04-24 09:05:12.849858-07:00[autovideoconverter] Processing watch folder '/watch'...
2024-04-24 09:05:12.858027-07:00[autovideoconverter] Waiting 5 seconds before processing '/watch/2023-12-23 15-44-52.mkv'...
2024-04-24 09:05:18.392169-07:00[autovideoconverter] Starting conversion of '/watch/2023-12-23 15-44-52.mkv' (6a60ab33727221f52bd6a9bc8e3ff3fc) using preset 'AV1QSV3.0'...
2024-04-24 09:05:18.392215-07:00[autovideoconverter] 1 title(s) to process.
2024-04-24 09:05:19.983649-07:00[autovideoconverter] Conversion ended successfully.
2024-04-24 09:05:19.986517-07:00[autovideoconverter] Removing '/watch/2023-12-23 15-44-52.mkv'...
2024-04-24 09:05:19.987382-07:00[autovideoconverter] Removed '/watch/2023-12-23 15-44-52.mkv'.
2024-04-24 09:05:19.989943-07:00[autovideoconverter] Watch folder '/watch' processing terminated.
2024-04-24 09:05:24.999299-07:00[autovideoconverter] Change detected in watch folder '/watch'.
2024-04-24 09:05:25.001183-07:00[autovideoconverter] Processing watch folder '/watch'...
2024-04-24 09:05:25.007790-07:00[autovideoconverter] Watch folder '/watch' processing terminated.

Container inspect

No response

Anything else?

Opening /watch/2023-12-23 15-44-52.mkv...
[09:05:18] CPU: AMD Ryzen 5 5600X 6-Core Processor
[09:05:18] - logical processor count: 12
[09:05:18] Intel Quick Sync Video support: yes
[09:05:18] Intel Quick Sync Video discrete adapter with index 0 and renderD128
[09:05:18] Impl mfx-gen library path: /usr/lib/libmfx-gen.so.1.2.9
[09:05:18] - Intel Media SDK hardware: API 2.9 (minimum: 1.3)
[09:05:18] - Decode support: h264 hevc (8bit: yes, 10bit: yes) av1 (8bit: yes, 10bit: yes)
[09:05:18] - H.264 encoder: yes
[09:05:18] - preferred implementation: hardware (any) via ANY
[09:05:18] - capabilities (hardware): lowpower breftype icq vsinfo chromalocinfo opt1 opt2+mbbrc+extbrc+trellis+repeatpps+ib_adapt+nmpslice
[09:05:18] - H.265 encoder: yes (8bit: yes, 10bit: yes)
[09:05:18] - preferred implementation: hardware (any) via ANY
[09:05:18] - capabilities (hardware): lowpower bpyramid icq vsinfo masteringinfo cllinfo opt1
[09:05:18] - AV1 encoder: yes (8bit: yes, 10bit: yes)
[09:05:18] - preferred implementation: hardware (any) via ANY
[09:05:18] - capabilities (hardware): lowpower bpyramid icq vsinfo masteringinfo cllinfo opt1 av1bitstream
[09:05:18] hb_scan: path=/watch/2023-12-23 15-44-52.mkv, title_index=1
Input #0, matroska,webm, from '/watch/2023-12-23 15-44-52.mkv':
Metadata:
ENCODER : Lavf60.3.100
Duration: 00:01:27.27, start: 0.000000, bitrate: 2669 kb/s
Stream #0:0: Video: h264 (High), yuv420p(tv, bt709, progressive), 1280x720 [SAR 1:1 DAR 16:9], 30 fps, 30 tbr, 1k tbn
Metadata:
DURATION : 00:01:27.266000000
Stream #0:1: Audio: aac (LC), 48000 Hz, stereo, fltp
Metadata:
title : simple_aac
DURATION : 00:01:27.168000000
[09:05:18] scan: decoding previews for title 1
[09:05:18] scan: audio 0x1: aac, rate=48000Hz, bitrate=1 Unknown (AAC LC, 2.0 ch)
[09:05:18] using bitstream PAR 1:1
[09:05:18] scan: 10 previews, 1280x720, 30.000 fps, autocrop = 0/0/0/0, aspect 16:9, PAR 1:1, color profile: 1-1-1, chroma location: left
[09:05:18] scan: supported video decoders: avcodec qsv
[09:05:18] libhb: scan thread found 1 valid title(s)

• Using preset: AV1QSV3.0
• title 1:
  • stream: /watch/2023-12-23 15-44-52.mkv
  • duration: 00:01:27
  • size: 1280x720, pixel aspect: 1/1, display aspect: 1.78, 30.000 fps
  • autocrop: 0/0/0/0
  • chapters:
    • 1: duration 00:01:27
  • audio tracks:
    • 1, Unknown (AAC LC, 2.0 ch) (iso639-2: und)
  • subtitle tracks:
    [09:05:18] Starting work at: Wed Apr 24 09:05:18 2024

[09:05:18] 1 job(s) to process
[09:05:18] json job:
{
"Audio": {
"AudioList": [
{
"Bitrate": 160,
"CompressionLevel": -1.0,
"DRC": 0.0,
"DitherMethod": "auto",
"Encoder": "opus",
"Gain": 0.0,
"Mixdown": "stereo",
"Name": "simple_aac",
"NormalizeMixLevel": false,
"PresetEncoder": "opus",
"Quality": -3.0,
"Samplerate": 0,
"Track": 0
}
],
"CopyMask": [
"copy:aac"
],
"FallbackEncoder": "none"
},
"Destination": {
"AlignAVStart": false,
"ChapterList": [
{
"Duration": {
"Hours": 0,
"Minutes": 1,
"Seconds": 27,
"Ticks": 7853940
},
"Name": ""
}
],
"ChapterMarkers": false,
"File": "/output/.gDqVzf/2023-12-23 15-44-52.mkv",
"InlineParameterSets": false,
"Mux": "mkv",
"Options": {
"IpodAtom": false,
"Optimize": false
}
},
"Filters": {
"FilterList": [
{
"ID": 10,
"Settings": {
"mode": 1
}
},
{
"ID": 19,
"Settings": {
"crop-bottom": 0,
"crop-left": 0,
"crop-right": 0,
"crop-top": 0,
"height": 720,
"width": 1280
}
}
]
},
"Metadata": {},
"PAR": {
"Den": 1,
"Num": 1
},
"SequenceID": 0,
"Source": {
"Angle": 0,
"HWDecode": 0,
"Path": "/watch/2023-12-23 15-44-52.mkv",
"Range": {
"End": 1,
"Start": 1,
"Type": "chapter"
},
"Title": 1
},
"Subtitle": {
"Search": {
"Burn": true,
"Default": false,
"Enable": false,
"Forced": false
},
"SubtitleList": []
},
"Video": {
"ChromaLocation": 1,
"ColorInputFormat": 0,
"ColorMatrix": 1,
"ColorOutputFormat": 0,
"ColorPrimaries": 1,
"ColorRange": 1,
"ColorTransfer": 1,
"Encoder": "qsv_av1_10bit",
"HardwareDecode": 0,
"Level": "auto",
"MultiPass": false,
"Options": "",
"Preset": "quality",
"Profile": "auto",
"QSV": {
"AdapterIndex": 0,
"AsyncDepth": 0,
"Decode": true
},
"Quality": 24.0,
"Tune": "",
"Turbo": false
}
}
[09:05:18] qsv: discrete qsv adapter with index 0 has been selected
[09:05:18] Starting Task: Encoding Pass
[09:05:18] work: skipping crop/scale filter
[09:05:18] work: compression level not specified, track 1 setting compression level 10.00
[09:05:18] job configuration:
[09:05:18] * source
[09:05:18] + /watch/2023-12-23 15-44-52.mkv
[09:05:18] + title 1, chapter(s) 1 to 1
[09:05:18] + container: matroska,webm
[09:05:18] + data rate: 2669 kbps
[09:05:18] * destination
[09:05:18] + /output/.gDqVzf/2023-12-23 15-44-52.mkv
[09:05:18] + container: Matroska (libavformat)
[09:05:18] * video track
[09:05:18] + decoder: h264_qsv 8-bit (yuv420p)
[09:05:18] + filters
[09:05:18] + Framerate Shaper (mode=1)
[09:05:18] + frame rate: 30.000 fps -> constant 30.000 fps
[09:05:18] + Format (format=p010le)
[09:05:18] + Output geometry
[09:05:18] + storage dimensions: 1280 x 720
[09:05:18] + pixel aspect ratio: 1 : 1
[09:05:18] + display dimensions: 1280 x 720
[09:05:18] + encoder: AV1 10-bit (Intel Media SDK)
[09:05:18] + preset: quality
[09:05:18] + profile: auto
[09:05:18] + level: auto
[09:05:18] + quality: 24.00 (ICQ)
[09:05:18] + color profile: 1-1-1
[09:05:18] + chroma location: left
[09:05:18] * audio track 1
[09:05:18] + name: simple_aac
[09:05:18] + decoder: Unknown (AAC LC, 2.0 ch) (track 1, id 0x1)
[09:05:18] + samplerate: 48000 Hz
[09:05:18] + mixdown: Stereo
[09:05:18] + encoder: Opus (libopus)
[09:05:18] + bitrate: 160 kbps, samplerate: 48000 Hz
[09:05:18] + compression level: 10.00
[09:05:18] sync: expecting 2617 video frames
libva info: VA-API version 1.20.0
libva info: User environment variable requested driver 'iHD'
libva info: Trying to open /usr/lib/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_20
libva info: va_openDriver() returns 0
libva info: VA-API version 1.20.0
libva info: User environment variable requested driver 'iHD'
libva info: Trying to open /usr/lib/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_20
libva info: va_openDriver() returns 0
[09:05:18] hb_display_init: using VA driver 'iHD'
libva info: VA-API version 1.20.0
libva info: User environment variable requested driver 'iHD'
libva info: Trying to open /usr/lib/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_20
libva info: va_openDriver() returns 0
[09:05:18] encqsvInit: using encode-only via system memory (LowPower) path
[09:05:18] encqsvInit: AV1 Main profile @ level 3.1
[09:05:18] encqsvInit: TargetUsage 1 AsyncDepth 6
[09:05:18] encqsvInit: GopRefDist 8 GopPicSize 64 NumRefFrame 4 IdrInterval 0
[09:05:18] encqsvInit: BFramesMax 7 BRefType pyramid
[09:05:18] encqsvInit: RateControlMethod ICQ ICQQuality 24
libva info: VA-API version 1.20.0
libva info: User environment variable requested driver 'iHD'
libva info: Trying to open /usr/lib/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_20
libva info: va_openDriver() returns 0
libva info: VA-API version 1.20.0
libva info: User environment variable requested driver 'iHD'
libva info: Trying to open /usr/lib/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_20
libva info: va_openDriver() returns 0

[JonathonSunshine]

I'm having this as well, I don't get much info in the docker logs but I'm running on Unraid 6.12.9 with Thor's custom kernal so I can use an Intel Arc GPU and get this in the Unraid logs

May 3 23:12:43 SERVER-3600 kernel: HandBrakeCLI[10626]: segfault at 14cdc26b9000 ip 000014cdc88b9575 sp 000014cdc26b2c68 error 6 in ld-musl-x86_64.so.1[14cdc887a000+4b000] likely on CPU 0 (core 0, socket 0)

[facesandaces]

I am having the same issue. Any time I attempt to use any custom preset for the automated encoding, the logs will show a successful completion of the encode (as shown below), but the resultant output will be 1kb. If I default the field in the docker container stipulating a custom preset, the encode proceeds normally at the default Fast1080p30 preset. If I attempt to manually use any custom preset I created, the encode complete normally.

It's only when I specify a custom preset in the automated process.

[cont-init ] 89-info.sh: terminated successfully.
[cont-init ] all container initialization scripts executed.
[init ] giving control to process supervisor.
[supervisor ] loading services...
[supervisor ] loading service 'default'...
[supervisor ] loading service 'app'...
[supervisor ] loading service 'gui'...
[supervisor ] loading service 'certsmonitor'...
[supervisor ] service 'certsmonitor' is disabled.
[supervisor ] loading service 'nginx'...
[supervisor ] loading service 'xvnc'...
[supervisor ] loading service 'openbox'...
[supervisor ] loading service 'logmonitor'...
[supervisor ] service 'logmonitor' is disabled.
[supervisor ] loading service 'logrotate'...
[supervisor ] loading service 'autovideoconverter'...
[supervisor ] all services loaded.
[supervisor ] starting services...
[supervisor ] starting service 'xvnc'...
[xvnc ] Xvnc TigerVNC 1.13.1 - built Dec 21 2023 00:54:05
[xvnc ] Copyright (C) 1999-2022 TigerVNC Team and many others (see README.rst)
[xvnc ] See https://www.tigervnc.org for information on TigerVNC.
[xvnc ] Underlying X server release 12014000
[xvnc ] Thu May 9 22:37:37 2024
[xvnc ] vncext: VNC extension running!
[xvnc ] vncext: Listening for VNC connections on /tmp/vnc.sock (mode 0660)
[xvnc ] vncext: Listening for VNC connections on all interface(s), port 5900
[xvnc ] vncext: created VNC server for screen 0
[supervisor ] starting service 'nginx'...
[nginx ] Listening for HTTP connections on port 5800.
[supervisor ] starting service 'openbox'...
[supervisor ] starting service 'app'...
[supervisor ] starting service 'autovideoconverter'...
[autovideoconverter] Processing watch folder '/watch'...
[autovideoconverter] Skipping video '/watch/1.mp4' (218f37ccb22560562e0e7533d949db9e): already processed successfully.
[autovideoconverter] Watch folder '/watch' processing terminated.
[supervisor ] all services started.
[xvnc ] Thu May 9 22:37:47 2024
[xvnc ] Connections: accepted: /tmp/vnc.sock
[xvnc ] SConnection: Client needs protocol version 3.8
[xvnc ] SConnection: Client requests security type None(1)
[xvnc ] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888
[xvnc ] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888
[xvnc ] ComparingUpdateTracker: 0 pixels in / 0 pixels out
[xvnc ] ComparingUpdateTracker: (1:-nan ratio)
[autovideoconverter] Change detected in watch folder '/watch'.
[autovideoconverter] Processing watch folder '/watch'...
[autovideoconverter] Waiting 5 seconds before processing '/watch/2.mp4'...
[autovideoconverter] Starting conversion of '/watch/2.mp4' (c0930d84679045f56edb32a6ed2c3209) using preset 'My Hardware/H264 QSV'...
[autovideoconverter] 1 title(s) to process.
[autovideoconverter] Conversion ended successfully.
[autovideoconverter] Watch folder '/watch' processing terminated.

[TNFB]

#347 look at my comment and don't hesitate to reply !

[ilfat12]

I have the same problem and segfault in the dmesg output:
HandBrakeCLI[1854888]: segfault at 7f4b5454e000 ip 00007f4b59ec747a sp 00007f4b54547e38 error 6 in ld-musl-x86_64.so.1[7f4b59e81000+54000] likely on CPU 0 (core 0, socket 0)
But it works fine in the GUI

[TNFB]

I have the same problem and segfault in the dmesg output: HandBrakeCLI[1854888]: segfault at 7f4b5454e000 ip 00007f4b59ec747a sp 00007f4b54547e38 error 6 in ld-musl-x86_64.so.1[7f4b59e81000+54000] likely on CPU 0 (core 0, socket 0) But it works fine in the GUI

Can you try this ? #347 (comment)
The only thing that change between the GUI and the automatic converter is that the GUI uses software decoding and autoconverter don't.

[ilfat12]

Can you try this ? #347 (comment)

Yes, with AUTOMATED_CONVERSION_HANDBRAKE_CUSTOM_ARGS=--disable-qsv-decoding it is works.
And I think the hw decoding is still working because the average FPS is about 350 and CPU usage is 80-90%,
if I choose x264 encoder, FPS less than 30 and CPU usage is 100%

The only thing that change between the GUI and the automatic converter is that the GUI uses software decoding and autoconverter don't.

I don't think so. In the GUI FPS is more than 300 which is not possible for my Celeron N5105 I think

[ilfat12]

Can you try this ? #347 (comment)

Thanks for the tip, by the way :)
I wasn't paying attention when I first looked at #347

[micahs72]

I ran into this problem, too. I could use automatic encoding for QSV720 but not QSV1080, and with no error message. I could xcode the same video file with that same profile in the gui, so I knew it wasn't a permissions issue. Figured it must be a config issue on my end. Found this thread and finally got the solution.

Adding "AUTOMATED_CONVERSION_HANDBRAKE_CUSTOM_ARGS=--disable-qsv-decoding" fixed it.

Could this be added to the docs? Thx!