search

jlesage / docker-handbrake

Docker container for HandBrake
MIT License
855 stars 97 forks source link

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

Open Aerochill opened 6 months ago

Aerochill commented 6 months ago

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

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)

[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 commented 6 months ago

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 commented 6 months ago

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 commented 4 months ago

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

ilfat12 commented 3 months ago

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 commented 3 months ago

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 ? https://github.com/jlesage/docker-handbrake/issues/347#issuecomment-2222509081 The only thing that change between the GUI and the automatic converter is that the GUI uses software decoding and autoconverter don't.

ilfat12 commented 3 months ago

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 commented 3 months ago

Can you try this ? #347 (comment)

Thanks for the tip, by the way :) I wasn't paying attention when I first looked at https://github.com/jlesage/docker-handbrake/issues/347