joshuaboniface / rffmpeg

rffmpeg: remote SSH FFmpeg wrapper tool
GNU General Public License v3.0
655 stars 51 forks source link

Finished rffmpeg 32852 with return code 127 #10

Closed Floflobel closed 3 years ago

Floflobel commented 3 years ago

Hello,

I am trying to get your script to work on Emby. I know well that it is not suitable for Emby but for Jellyfin but I am waiting for a long time for the mobile application to support chromecast. Unfortunately this is what is blocking me from making the switch.

I read and reread the script and I think I found the problem. It seems to be a character escape problem in my media path.

Here is a history of my logs when I run ffmpeg remotely:

2021-04-27 21:38:33,147 - rffmpeg - INFO - Starting process loop
2021-04-27 21:38:33,147 - rffmpeg - INFO - Determining target host
2021-04-27 21:38:33,148 - rffmpeg - INFO - Selected valid target host 192.168.1.182
2021-04-27 21:38:33,148 - rffmpeg - INFO - [rffmpeg] Running on 192.168.1.182
2021-04-27 21:38:33,148 - rffmpeg - INFO - Crafting remote command string
2021-04-27 21:38:33,148 - rffmpeg - INFO - Running rffmpeg 38953 on emby@192.168.1.182
2021-04-27 21:38:33,148 - rffmpeg - INFO - Remote command for rffmpeg 38953: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-2a47d6f1-f34a-43e9-a1e0-fe8b1caf2ce8_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4_%d.vtt
2021-04-27 21:38:33,148 - rffmpeg - INFO - Running command ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-2a47d6f1-f34a-43e9-a1e0-fe8b1caf2ce8_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4_%d.vtt
2021-04-27 21:38:33,154 - rffmpeg - INFO - Finished rffmpeg 38953 with return code 127

In this example you can see the error on the "(" character. Here is an example when I run the command manually:

ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-2a47d6f1-f34a-43e9-a1e0-fe8b1caf2ce8_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4_%d.vtt
bash: -c: line 0: syntax error near unexpected token `('
bash: -c: line 0: `/opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-2a47d6f1-f34a-43e9-a1e0-fe8b1caf2ce8_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i /media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv -filter_complex [0:0]format@f1=pix_fmts=yuv420p[f1_out0] -map [f1_out0] -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4_%d.vtt'

To get around the problem manually I escaped completely the path of my media (space, parenthesis, ect...):

ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-2a47d6f1-f34a-43e9-a1e0-fe8b1caf2ce8_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion\ \(2016\)/LION\ 2016\ MULTi\ VFF\ 1080p\ BluRay\ E-AC3\ x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8CE3C8_s4_%d.vtt

So I edited this path:

"/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv"

To:

"/media/storage3/films/Lion\ \(2016\)/LION\ 2016\ MULTi\ VFF\ 1080p\ BluRay\ E-AC3\ x265-Winks.mkv"

I tried to edit the python script but I'm not an expert in this. I think the problem is the same under Jellyfin if I understood everything correctly.

If you have an idea to unblock me, it would be really cool.

joshuaboniface commented 3 years ago

It should work fine with Emby.

I don't think the problem is the parentheses; they are escaped in the real call via the double-quotes, and I have those too without issues. I suspect the BASH error is a red herring.

Exit code 127 is actually a file not found, and I suspect the issue there is the %d that Emby is inserting in the filenames. But I can't say for certain offhand. I'll take a closer look later to see.

Floflobel commented 3 years ago

Again, many thanks for this script and the time you spent answering me.

If you need any help with anything to debug the problem, don't hesitate to ask me.

For information the script works well by calling the local ffmpeg of the machine:

2021-04-27 22:38:16,426 - rffmpeg - INFO - Starting process loop
2021-04-27 22:38:16,448 - rffmpeg - INFO - Determining target host
2021-04-27 22:38:16,448 - rffmpeg - INFO - Selected valid target host localhost
2021-04-27 22:38:16,448 - rffmpeg - INFO - [rffmpeg] Running on localhost
2021-04-27 22:38:16,448 - rffmpeg - INFO - Local command for rffmpeg 41943: /opt/emby-server/bin/old_ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-97f9dd5c-3e77-4333-a53c-856f4209cb09_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 h264 -i /media/storage4/films/The Marksman (2021)/The.Marksman.2021.CUSTOM.FRENCH.720p.BluRay.x264-FRATERNiTY.mkv -filter_complex [0:2]scale@f1=width=720:height=300[f1_out0] -map [f1_out0] -map 0:0 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 1116000 -bufsize:v:0 2232000 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 3.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/D072A6.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_%d.ts -map 0:1 -map 0:2 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_s1.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_s1_%d.vtt
2021-04-27 22:38:16,449 - rffmpeg - INFO - Running command /opt/emby-server/bin/old_ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-97f9dd5c-3e77-4333-a53c-856f4209cb09_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 h264 -i /media/storage4/films/The Marksman (2021)/The.Marksman.2021.CUSTOM.FRENCH.720p.BluRay.x264-FRATERNiTY.mkv -filter_complex [0:2]scale@f1=width=720:height=300[f1_out0] -map [f1_out0] -map 0:0 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 1116000 -bufsize:v:0 2232000 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 3.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/D072A6.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_%d.ts -map 0:1 -map 0:2 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_s1.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/D072A6_s1_%d.vtt
2021-04-27 22:38:29,450 - rffmpeg - INFO - Finished local rffmpeg 41943 with return code 0
2021-04-27 22:38:29,459 - rffmpeg - INFO - Finished rffmpeg 41943 with return code 0
joshuaboniface commented 3 years ago

Interesting, OK - the BASH syntax error is definitely a red herring - it seems the Python subprocess.run can handle the unquoted SSH arguments while BASH can't. To test, try putting single-quotes (') around everything after the user@ip_address portion (i.e. the /opt/emby ffmpeg and then everything else). That should give a good indication of what's going on.

Floflobel commented 3 years ago

Indeed it works when I run the command manually with the '.

But when I launch via rffmpeg I get the same error:

2021-04-27 23:17:40,256 - rffmpeg - INFO - Starting process loop
2021-04-27 23:17:40,256 - rffmpeg - INFO - Determining target host
2021-04-27 23:17:40,263 - rffmpeg - INFO - Selected valid target host 192.168.1.182
2021-04-27 23:17:40,263 - rffmpeg - INFO - [rffmpeg] Running on 192.168.1.182
2021-04-27 23:17:40,263 - rffmpeg - INFO - Crafting remote command string
2021-04-27 23:17:40,263 - rffmpeg - INFO - Running rffmpeg 43299 on emby@192.168.1.182
2021-04-27 23:17:40,264 - rffmpeg - INFO - Remote command for rffmpeg 43299: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 ' /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-49fcb961-d07c-4918-8698-d336c370007d_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s4_%d.vtt '
2021-04-27 23:17:40,264 - rffmpeg - INFO - Running command ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 ' /opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-49fcb961-d07c-4918-8698-d336c370007d_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/8E3F8C_s4_%d.vtt '
2021-04-27 23:17:40,270 - rffmpeg - INFO - Finished rffmpeg 43299 with return code 127
joshuaboniface commented 3 years ago

Just one thought: are you running rffmpeg with the same user as would run the process within Emby? I assume so but want to be sure. Same thing with the manual run of the SSH command?

Floflobel commented 3 years ago

Concerning rffmpeg it is launched via Emby automatically, therefore with the user "emby".

I had forgotten to launch manually the command with the user "emby", but I just did it and I had no problem. I can see the transcoding being done.

For your information, I made a change in the code to test the addition of '.

I saw that you updated the script, do you want me, to test it ?

Floflobel commented 3 years ago

I just updated the script and let Emby run it, unfortunately it didn't work:

2021-04-28 01:01:40,710 - rffmpeg - INFO - Running as emby@192.168.1.182
2021-04-28 01:01:40,710 - rffmpeg - INFO - Remote command: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 '/opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-0aefd49b-0aee-4d23-994d-d20d486477de_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/94A4A3_s4_%d.vtt'
2021-04-28 01:01:40,715 - rffmpeg - ERROR - Finished rffmpeg PID 49326 with return code 127
2021-04-28 01:01:41,223 - rffmpeg - INFO - Starting rffmpeg PID 49328
2021-04-28 01:01:41,223 - rffmpeg - INFO - Determining target host
2021-04-28 01:01:41,226 - rffmpeg - INFO - Found running rffmpeg process 46696 against host 'localhost'
2021-04-28 01:01:41,226 - rffmpeg - INFO - Selected target host '192.168.1.182'
2021-04-28 01:01:41,227 - rffmpeg - INFO - Running as emby@192.168.1.182
2021-04-28 01:01:41,230 - rffmpeg - INFO - Remote command: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 '/opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-d107bb4f-2088-4c38-8a2e-8c4bcfb85afa_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s4_%d.vtt'
2021-04-28 01:01:41,248 - rffmpeg - ERROR - Finished rffmpeg PID 49328 with return code 127
joshuaboniface commented 3 years ago

OK yea none of the changes I've made should have affected this. I did add those quotes to the output print, but this does not affect the actual command that gets passed to subprocess to execute.

That 127 exit code must be coming from something wrong with ffmpeg, as I can't think of anything on the rffmpeg side that would be causing it. Especially if it works perfectly fine when run manually.

What is the output of the manual ssh command? That may help narrow it down.

joshuaboniface commented 3 years ago

For comparison, here's one of my runs (manual via CLI) of a media item with the parenthesis, so it can't be that:

2021-04-27 18:16:35,665 - rffmpeg - INFO - Starting rffmpeg PID 8429
2021-04-27 18:16:35,666 - rffmpeg - INFO - Determining target host
2021-04-27 18:16:35,666 - rffmpeg - INFO - Found running rffmpeg process 8421 against host 'base'
2021-04-27 18:16:35,667 - rffmpeg - INFO - Selected target host 'base'
2021-04-27 18:16:35,667 - rffmpeg - INFO - Running as jellyfin@base
2021-04-27 18:16:35,667 - rffmpeg - INFO - Remote command: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /srv/id_ed25519.jellyfin jellyfin@base '/usr/lib/jellyfin-ffmpeg/ffmpeg -c:v h264_cuvid -resize 1920x1080 -i "file:/srv/media/Video/Movies/Matilda (1996)/Matilda (1996).mkv" -map_metadata -1 -map_chapters -1 -threads 2 -map 0:0 -map 0:1 -codec:v:0 h264_nvenc -pix_fmt yuv420p -preset default -b:v 9360000
-maxrate 9360000 -bufsize 18720000 -profile:v:0 high -g:v:0 72 -keyint_min:v:0 72 -sc_threshold:v:0 0 -filter_complex "[0:2]scale=1920x1080[sub];[0:0][sub]overlay" -start_at_zero -vsync -1 -codec:a:0 aac -ac 6 -ab 640000 -copyts -avoid_negative_ts disabled -max_muxing_queue_size 2048 -f hls -max_delay 5000000 -hls_time 3 -hls_segment_type mpegts -start_number 0 -hls_segment_filename /srv/jellyfin/transcodes/07c23ee6e416ae0683ac48b4279a5773%d.ts -hls_playlist_type vod -hls_list_size 0 -y /srv/jellyfin/transcodes/07c23ee6e416ae0683ac48b4279a5773.m3u8'
2021-04-27 18:16:37,304 - rffmpeg - INFO - Finished rffmpeg PID 8429 with return code 0
Floflobel commented 3 years ago

Here is an example of launching via CLI with the complete command:

root@emby:~/rffmpeg # sudo -u emby  ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 '/opt/emby-server/bin/emby-ffmpeg -loglevel +timing -y -print_graphs_file /var/lib/emby/logs/ffmpeg-transcode-d107bb4f-2088-4c38-8a2e-8c4bcfb85afa_1graph.txt -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map "[f1_out0]" -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 subme=0:me_range=4:rc_lookahead=10:partitions=none -crf:v:0 26 -c:a:0 aac -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 volume=2 -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_%d.ts -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s3.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s3_%d.vtt -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s4.m3u8 -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 /var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s4_%d.vtt'
02:02:06.538 ffmpeg version 4.3.0-emby_2021_02_21 Copyright (c) 2000-2021 the FFmpeg developers and softworkz for Emby LLC
02:02:06.538   built with gcc 8.3.0 (crosstool-NG 1.24.0)
02:02:06.538 Execution Date: 2021-04-28 02:02:06
02:02:06.841 [matroska,webm @ 0x1a2c1c0] Could not find codec parameters for stream 5 (Subtitle: hdmv_pgs_subtitle (pgssub)): unspecified size
Consider increasing the value for the 'analyzeduration' and 'probesize' options
02:02:06.842 [matroska,webm @ 0x1a2c1c0] Could not find codec parameters for stream 6 (Subtitle: hdmv_pgs_subtitle (pgssub)): unspecified size
Consider increasing the value for the 'analyzeduration' and 'probesize' options
02:02:06.842 Guessed Channel Layout for Input Stream #0.1 : 5.1
02:02:06.842 Input #0, matroska,webm, from '/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv':
02:02:06.842   Metadata:
02:02:06.842     title           : LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks
02:02:06.843     ENCODING_INFO   : MATROSKA,WEBM > MKV 1080p 10-bit
02:02:06.843     creation_time   : 2021-04-27T05:39:01.000000Z
02:03:02.057     MEDIA_TYPE      : 9
02:03:02.057     HD_VIDEO        : 1
02:03:02.057     ARTIST          : Winks
02:03:02.057     DATE            : 2016-01-20
02:03:02.057     GENRE           : Drame
02:03:02.057     PUBLISHER       : The Weinstein Company, See-Saw Films, Screen Australia, Aquarius Films, Sunstar Entertainment
02:03:02.057     DESCRIPTION     : Une incroyable histoire vraie :  À 5 ans, Saroo se retrouve seul dans un train traversant l’Inde qui l’emmène malgré lui à des milliers de kilomètres de sa famille. Perdu, le petit garçon doit apprendre à survivre seul dans l’immense ville de
02:03:02.057     ACTORS          : Dev Patel, Rooney Mara, David Wenham, Nicole Kidman, Abhishek Bharate, Divian Ladwa, Priyanka Bose, Deepti Naval, Tannishtha Chatterjee, Nawazuddin Siddiqui, Sunny Pawar, Keshav Jadhav, Benjamin Rigby, Riddhi Sen, Rita Boy, Arka Das, Emilie Cocquerel, Sac
02:03:02.057     DIRECTOR        : Garth Davis
02:03:02.057     PRODUCER        : Emile Sherman, Iain Canning, Angie Fielder
02:03:02.057     WRITER          : Luke Davies
02:03:02.057     COUNTRY         : Australia, United Kingdom, United States
02:03:02.057     RATING          : 8.10
02:03:02.057     ENCODER         : Lavf58.45.100
02:03:02.057   Duration: 01:58:34.09, start: 0.000000, bitrate: 6632 kb/s
02:03:02.057     Stream #0:0(fre): Video: hevc (Main 10), yuv420p10le(tv, bt709), 1920x800, SAR 1:1 DAR 12:5, Level 123, 23.86 fps, 23.86 tbr, 1k tbn, 23.86 tbc (default)
02:03:02.057     Metadata:
02:03:02.057       title           : LION 2016
02:03:02.057       BPS             : 5017770
02:03:02.057       DURATION        : 01:58:34.088000000
02:03:02.057       NUMBER_OF_FRAMES: 169763
02:03:02.057       NUMBER_OF_BYTES : 4462107992
02:03:02.057     Stream #0:1(fre): Audio: eac3, 48000 Hz, 5.1, fltp (default)
02:03:02.057     Metadata:
02:03:02.057       title           : Truefrench
02:03:02.057       BPS             : 960000
02:03:02.057       DURATION        : 01:58:34.080000000
02:03:02.057       NUMBER_OF_FRAMES: 222315
02:03:02.057       NUMBER_OF_BYTES : 853689600
02:03:02.057     Stream #0:2(eng): Audio: ac3, 48000 Hz, 5.1(side), fltp, 640 kb/s
02:03:02.057     Metadata:
02:03:02.057       title           : Anglais
02:03:02.057       BPS             : 640000
02:03:02.057       DURATION        : 01:58:32.384000000
02:03:02.057       NUMBER_OF_FRAMES: 222262
02:03:02.057       NUMBER_OF_BYTES : 568990720
02:03:02.057     Stream #0:3(fre): Subtitle: subrip (default) (forced)
02:03:02.057     Metadata:
02:03:02.057       title           : French Forces SRT
02:03:02.057       ENCODING_INFO   : SUBRIP > SUBRIP
02:03:02.057       BPS             : 1
02:03:02.057       DURATION        : 01:55:47.440000000
02:03:02.057       NUMBER_OF_FRAMES: 46
02:03:02.057       NUMBER_OF_BYTES : 1437
02:03:02.057     Stream #0:4(fre): Subtitle: subrip
02:03:02.057     Metadata:
02:03:02.057       title           : French Full SRT
02:03:02.057       ENCODING_INFO   : SUBRIP > SUBRIP
02:03:02.057       BPS             : 24
02:03:02.057       DURATION        : 01:55:47.440000000
02:03:02.057       NUMBER_OF_FRAMES: 917
02:03:02.057       NUMBER_OF_BYTES : 21423
02:03:02.057     Stream #0:5(fre): Subtitle: hdmv_pgs_subtitle
02:03:02.057     Metadata:
02:03:02.057       title           : French Forces
02:03:02.057       ENCODING_INFO   : HDMV_PGS_SUBTITLE > COPY Fast
02:03:02.057       BPS             : 7087
02:03:02.057       DURATION        : 01:55:47.399000000
02:03:02.057       NUMBER_OF_FRAMES: 642
02:03:02.057       NUMBER_OF_BYTES : 6154672
02:03:02.057     Stream #0:6(fre): Subtitle: hdmv_pgs_subtitle
02:03:02.057     Metadata:
02:03:02.057       title           : French Full SDH
02:03:02.057       ENCODING_INFO   : HDMV_PGS_SUBTITLE > COPY Fast
02:03:02.057       BPS             : 27211
02:03:02.057       DURATION        : 01:55:47.399000000
02:03:02.057       NUMBER_OF_FRAMES: 2272
02:03:02.057       NUMBER_OF_BYTES : 23631360
02:03:02.057     Stream #0:7(und): Video: png, rgb24(pc), 500x700 [SAR 5900:5900 DAR 5:7], 90k tbr, 90k tbn, 90k tbc (attached pic)
02:03:02.057     Metadata:
02:03:02.057       filename        : poster
02:03:02.057       mimetype        : image/png
02:03:02.057       ENCODING_INFO   : PNG > COPY Fast
02:03:02.057       LANGUAGE        : und
02:03:02.178 Output #1, segment, to '/var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s3_%d.vtt':
02:03:02.178   Metadata:
02:03:02.178     encoder         : Lavf58.35.100
02:03:02.178     Stream #1:0: Subtitle: webvtt (default) (forced)
02:03:02.178     Metadata:
02:03:02.178       encoder         : Lavc58.62.100 webvtt
02:03:02.178     Stream #1:1: Video: hevc (Main 10), yuv420p10le(tv, bt709), 1920x800 [SAR 1:1 DAR 12:5], q=2-31, Level 123, 23.86 fps, 23.86 tbr, 23.86 tbn, 23.86 tbc (default)
02:03:02.190 Output #2, segment, to '/var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_s4_%d.vtt':
02:03:02.190   Metadata:
02:03:02.190     encoder         : Lavf58.35.100
02:03:02.190     Stream #2:0: Subtitle: webvtt
02:03:02.190     Metadata:
02:03:02.190       encoder         : Lavc58.62.100 webvtt
02:03:02.190     Stream #2:1: Video: hevc (Main 10), yuv420p10le(tv, bt709), 1920x800 [SAR 1:1 DAR 12:5], q=2-31, Level 123, 23.86 fps, 23.86 tbr, 23.86 tbn, 23.86 tbc (default)
02:03:02.190 Stream mapping:
02:03:02.190   Stream #0:0 (hevc) -> format (graph 0)
02:03:02.190   format (graph 0) -> Stream #0:0 (libx264)
02:03:02.190   Stream #0:1 -> #0:1 (eac3 (native) -> aac (native))
02:03:02.190   Stream #0:3 -> #1:0 (subrip (srt) -> webvtt (native))
02:03:02.190   Stream #0:0 -> #1:1 (copy)
02:03:02.190   Stream #0:4 -> #2:0 (subrip (srt) -> webvtt (native))
02:03:02.190   Stream #0:0 -> #2:1 (copy)
02:03:02.190 Press [q] to stop, [?] for help
02:03:02.412 [libx264 @ 0x9bc980] using SAR=1/1
02:03:02.412 [libx264 @ 0x9bc980] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
02:03:02.429 [libx264 @ 0x9bc980] profile High, level 4.0, 4:2:0, 8-bit
02:03:02.429 [libx264 @ 0x9bc980] 264 - core 161 r3039 544c61f - H.264/MPEG-4 AVC codec - Copyleft 2003-2021 - http://www.videolan.org/x264.html - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x3:0 me=hex subme=0 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=4 chroma_me=1 trellis=0 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=6 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=3 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=1 keyint=72 keyint_min=37 scenecut=0 intra_refresh=0 rc_lookahead=10 rc=crf mbtree=1 crf=26.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 vbv_maxrate=13265 vbv_bufsize=26531 crf_max=0.0 nal_hrd=none filler=0 ip_ratio=1.40 aq=1:1.00
02:03:02.431 Output #0, segment, to '/var/lib/emby/transcoding-temp/transcoding-temp/9F02F7_%d.ts':
02:03:02.431   Metadata:
02:03:02.431     encoder         : Lavf58.35.100
02:03:02.431     Stream #0:0: Video: h264 (libx264), yuv420p, 1920x800 [SAR 1:1 DAR 12:5], q=-1--1, 23.86 fps, 90k tbn, 23.86 tbc (default)
02:03:02.431     Metadata:
02:03:02.431       encoder         : Lavc58.62.100 libx264
02:03:02.431     Side data:
02:03:02.431       cpb: bitrate max/min/avg: 13265000/0/0 buffer size: 26531000 vbv_delay: N/A
02:03:02.431     Stream #0:1(fre): Audio: aac (LC), 48000 Hz, stereo, fltp, 192 kb/s (default)
02:03:02.431     Metadata:
02:03:02.431       encoder         : Lavc58.62.100 aac
^Croot@emby:~/rffmpeg #  fps=9.3 q=31.0 size=       8kB time=00:00:02.21 bitrate=  38.3kbits/s throttle=off speed=0.341x
Floflobel commented 3 years ago

It is indeed very strange that when I launch manually via CLI I have no problem, then when I pass via rffmpeg it returns an error code...

I continue to search at the same time but I don't really see what's going on.

We agree that the subprocess is also used locally to execute the command. The only difference with the remote command is that it doesn't go through SSH?

joshuaboniface commented 3 years ago

That's correct, the ssh portion of the command is the only difference.

Do the Emby logs indicate the exact parameters that rffmpeg is called with? In Jellyfin there's:

Apr 27 22:06:44 jf1 jellyfin[20384]: [22:06:44] [INF] [114] Jellyfin.Api.Controllers.DynamicHlsController: Current HLS implementation doesn't support non-keyframe breaks but one is requested, ignoring that request           
Apr 27 22:06:44 jf1 jellyfin[20384]: [22:06:44] [INF] [114] Jellyfin.Api.Helpers.TranscodingJobHelper: /usr/local/bin/ffmpeg -c:v h264_cuvid -resize 1920x1080 -i file:"/srv/media/Video/Movies/Matilda (1996)/Matilda (1996).mkv" -map_metadata -1 -map_chapters -1 -threads 2 -map 0:0 -map 0:1 -codec:v:0 h264_nvenc -pix_fmt yuv420p -preset default -b:v 9360000 -maxrate 9360000 -bufsize 18720000 -profile:v:0 high -g:v:0 72 -keyint_min:v:0 72 -sc_threshold:v:0 0 -filter_complex "[0:2]scale=1920x1080[sub];[0:0][sub]overlay" -start_at_zero -vsync -1 -codec:a:0 aac -ac 6 -ab 640000 -copyts -avoid_negative_ts disabled -max_muxing_queue_size 2048 -f hls -max_delay 5000000 -hls_time 3 -hls_segment_type mpegts -start_number 0 -hls_segment_filename "/srv/jellyfin/transcodes/1263c091b56b45838d4e97659ab25f66%d.ts" -hls_playlist_type vod -hls_list_size 0 -y "/srv/jellyfin/transcodes/1263c091b56b45838d4e97659ab25f66.m3u8"                         
Apr 27 22:06:44 jf1 jellyfin[20384]: [22:06:44] [DBG] [83] Jellyfin.Api.Helpers.TranscodingJobHelper: Launched FFmpeg process                                                                                                   
Apr 27 22:06:44 jf1 jellyfin[20384]: [22:06:44] [DBG] [83] Jellyfin.Api.Helpers.TranscodingJobHelper: Waiting for the creation of /srv/jellyfin/transcodes/1263c091b56b45838d4e97659ab25f660.ts                                 

and I believe Emby had something similar. I'm wondering if it fails if you run that iteration of the command. It might shed more light on the issue, perhaps some Python traceback or something.

Floflobel commented 3 years ago

Ok I just found the log and I also see an error after:

2021-04-28 21:44:18.405 Info App: ProcessRun 'StreamTranscode fd3d50' Execute: /opt/emby-server/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/var/lib/emby/logs/ffmpeg-transcode-fd3d50ac-f2b9-4418-945d-9466c094ea4e_1graph.txt" -copyts -start_at_zero -f matroska,webm -c:v:0 hevc -c:v:1 png -i "/media/storage3/films/Lion (2016)/LION 2016 MULTi VFF 1080p BluRay E-AC3 x265-Winks.mkv" -filter_complex "[0:0]format@f1=pix_fmts=yuv420p[f1_out0]" -map [f1_out0] -map 0:1 -sn -c:v:0 libx264 -g:v:0 72 -maxrate:v:0 13265852 -bufsize:v:0 26531704 -sc_threshold:v:0 0 -keyint_min:v:0 72 -pix_fmt:v:0 yuv420p -preset:v:0 veryfast -profile:v:0 high -level:v:0 4.0 -x264opts:v:0 "subme=0:me_range=4:rc_lookahead=10:partitions=none" -crf:v:0 26 -c:a:0 libmp3lame -ab:a:0 192000 -ac:a:0 2 -metadata:s:a:0 language=fre -filter:a:0 "volume=2" -disposition:a:0 default -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252.m3u8" -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252_%d.ts" -map 0:3 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252_s3.m3u8" -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252_s3_%d.vtt" -map 0:4 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252_s4.m3u8" -segment_list_type m3u8 -segment_time 3 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 "/var/lib/emby/transcoding-temp/transcoding-temp/4B7252_s4_%d.vtt"
2021-04-28 21:44:18.459 Info App: AppendExtraLogData - Read graph file: /var/lib/emby/logs/ffmpeg-transcode-fd3d50ac-f2b9-4418-945d-9466c094ea4e_1graph.txt
2021-04-28 21:44:18.459 Warn App: AppendExtraLogData: Unable read graph output file: /var/lib/emby/logs/ffmpeg-transcode-fd3d50ac-f2b9-4418-945d-9466c094ea4e_1graph.txt
2021-04-28 21:44:18.467 Info App: ProcessRun 'StreamTranscode fd3d50' Process exited with code 127
2021-04-28 21:44:18.511 Error Server: Error processing request
        *** Error Report ***
        Version: 4.6.0.40
        Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffdetect /opt/emby-server/bin/ffdetect -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -restartexitcode 3 -updatepackage emby-server-deb_{version}_amd64.deb
        Operating system: Linux version 5.4.0-70-generic (buildd@lcy01-amd64-004) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #78-Ubuntu SMP Fri Mar 19 13:29:52 UTC 2021
        Framework: .NET Core 3.1.13
        OS/Process: x64/x64
        Runtime: opt/emby-server/system/System.Private.CoreLib.dll
        Processor count: 4
        Data path: /var/lib/emby 
        Application path: /opt/emby-server/system
        System.Exception: System.Exception: Error starting ffmpeg
           at Emby.Server.MediaEncoding.Api.BaseStreamingService.StartFfMpeg(StreamState state, String outputPath, CancellationTokenSource cancellationTokenSource, Boolean acquireResources)
           at Emby.Server.MediaEncoding.Api.Hls.DynamicHlsService.GetDynamicSegment(StreamRequest request, String playlistId, String segmentId, Int32 subtitleStreamIndex)
           at Emby.Server.Implementations.Services.ServiceController.GetTaskResult(Task task)
           at Emby.Server.Implementations.Services.ServiceHandler.ProcessRequestAsync(HttpListenerHost appHost, IRequest httpReq, IResponse httpRes, RestPath restPath, String responseContentType, CancellationToken cancellationToken)
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.RequestHandler(IRequest httpReq, ReadOnlyMemory`1 urlString, ReadOnlyMemory`1 localPath, CancellationToken cancellationToken)
        Source: Emby.Server.MediaEncoding
        TargetSite: Void MoveNext()

It seems that there is an access problem on the file /var/lib/emby/logs/ffmpeg-transcode-fd3d50ac-f2b9-4418-945d-9466c094ea4e_1graph.txt and indeed it does not exist.

I also noticed that when testing another media, it launched well. However I have the impression that it is launched locally and not on my remote node. I say this because I don't see any CPU usage but how can I check be sure?

I show you the different logs:

2021-04-28 22:03:11,724 - rffmpeg - INFO - Starting rffmpeg PID 89512
2021-04-28 22:03:11,724 - rffmpeg - INFO - Determining target host
2021-04-28 22:03:11,725 - rffmpeg - INFO - Found running rffmpeg process 89411 against host 'localhost'
2021-04-28 22:03:11,725 - rffmpeg - INFO - Found running rffmpeg process 89098 against host 'localhost'
2021-04-28 22:03:11,725 - rffmpeg - INFO - Found running rffmpeg process 88396 against host 'localhost'
2021-04-28 22:03:11,725 - rffmpeg - INFO - Selected target host '192.168.1.182'
2021-04-28 22:03:11,725 - rffmpeg - INFO - Running as emby@192.168.1.182
2021-04-28 22:03:11,725 - rffmpeg - INFO - Remote command: ssh -q -o ConnectTimeout=1 -o ConnectionAttempts=1 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /var/lib/emby/.ssh/id_rsa emby@192.168.1.182 '/opt/emby-server/bin/emby-ffmpeg -i "file:/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.MULTi.WEBrip.1080p.x264.AAC_JiHEFF.mkv" -map 0:3 -an -vn /var/lib/emby/cache/temp/d2ea05c4af924e7e9dfd5efc16e093ed.vtt'
2021-04-28 22:03:11,728 - rffmpeg - ERROR - Finished rffmpeg PID 89512 with return code 127
2021-04-28 22:03:11.675 Info SubtitleEncoder: ProcessRun 'ffmpeg-subtitle_extract' Execute: /opt/emby-server/bin/ffmpeg -i file:"/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.MULTi.WEBrip.1080p.x264.AAC_JiHEFF.mkv" -map 0:3 -an -vn "/var/lib/emby/cache/temp/d2ea05c4af924e7e9dfd5efc16e093ed.vtt"
2021-04-28 22:03:11.734 Info SubtitleEncoder: ProcessRun 'ffmpeg-subtitle_extract' Process exited with code 127
2021-04-28 22:03:11.771 Error SubtitleEncoder: ffmpeg subtitle extraction failed for file:"/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.MULTi.WEBrip.1080p.x264.AAC_JiHEFF.mkv" to /var/lib/emby/cache/temp/d2ea05c4af924e7e9dfd5efc16e093ed.vtt
2021-04-28 22:03:11.771 Error SubtitleEncoder: ProcessRun 'ffmpeg-subtitle_extract' Output:
2021-04-28 22:03:11.771 Error SubtitleEncoder: ProcessRun 'ffmpeg-subtitle_extract' Error Output:
        ssh: relocation error: ssh: symbol ENGINE_register_all_complete version OPENSSL_1_1_0 not defined in file libcrypto.so.1.1 with link time reference
2021-04-28 22:03:11.786 Error Server: Error processing request
        *** Error Report ***
        Version: 4.6.0.40
        Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffdetect /opt/emby-server/bin/ffdetect -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -restartexi
tcode 3 -updatepackage emby-server-deb_{version}_amd64.deb
        Operating system: Linux version 5.4.0-70-generic (buildd@lcy01-amd64-004) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #78-Ubuntu SMP Fri Mar 19 13:29:52 UTC 2021
        Framework: .NET Core 3.1.13
        OS/Process: x64/x64
        Runtime: opt/emby-server/system/System.Private.CoreLib.dll
        Processor count: 4
        Data path: /var/lib/emby 
        Application path: /opt/emby-server/system
        System.Exception: System.Exception: ffmpeg subtitle extraction failed for file:"/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.MULTi.WEBrip.1080p.x264.AAC_JiHEFF.mkv" to /var/lib/emby/cache/te
mp/d2ea05c4af924e7e9dfd5efc16e093ed.vtt
           at Emby.Server.MediaEncoding.Subtitles.SubtitleEncoder.ExtractTextSubtitleInternal(String inputPath, String inputSubtitleCodec, Int32 subtitleStreamIndex, String outputCodec, String outputPath, Int64 st
artTimeTicks, Int64 endTimeTicks, Boolean preserveOriginalTimestamps, CancellationToken cancellationToken)
           at Emby.Server.MediaEncoding.Subtitles.SubtitleEncoder.ExtractTextSubtitle(ReadOnlyMemory`1 inputPath, String inputSubtitleCodec, MediaProtocol protocol, Int32 subtitleStreamIndex, String outputCodec, S
tring outputPath, Int64 startTimeTicks, Int64 endTimeTicks, Boolean preserveOriginalTimestamps, CancellationToken cancellationToken)
           at Emby.Server.MediaEncoding.Subtitles.SubtitleEncoder.GetReadableFile(String mediaPath, MediaProtocol mediaSourceProtocol, IDictionary`2 requestHeaders, MediaStream subtitleStream, ReadOnlyMemory`1 out
putFormat, Int64 startTimeTicks, Int64 endTimeTicks, Boolean preserveOriginalTimestamps, CancellationToken cancellationToken)
           at Emby.Server.MediaEncoding.Subtitles.SubtitleEncoder.GetSubtitles(String inputPath, MediaProtocol inputProtocol, IDictionary`2 requestHeaders, MediaStream subtitleStream, ReadOnlyMemory`1 outputFormat
, Int64 startTimeTicks, Int64 endTimeTicks, Boolean preserveOriginalTimestamps, CancellationToken cancellationToken)
           at MediaBrowser.Api.Subtitles.SubtitleService.GetSubtitles(GetSubtitle request, CancellationToken cancellationToken)
           at MediaBrowser.Api.Subtitles.SubtitleService.Get(GetSubtitle request)
           at Emby.Server.Implementations.Services.ServiceController.GetTaskResult(Task task)
           at Emby.Server.Implementations.Services.ServiceHandler.ProcessRequestAsync(HttpListenerHost appHost, IRequest httpReq, IResponse httpRes, RestPath restPath, String responseContentType, CancellationToken
 cancellationToken)
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.RequestHandler(IRequest httpReq, ReadOnlyMemory`1 urlString, ReadOnlyMemory`1 localPath, CancellationToken cancellationToken)
        Source: Emby.Server.MediaEncoding
        TargetSite: Void MoveNext()
Floflobel commented 3 years ago

I don't know why but after several tests it doesn't work anymore on the media that were working.

I tried to disable some options such as hardware transcoding and on-the-fly subtitle extraction.

Here is also an example of a transcoding log:

>> ThrottleBySegmentRequest: Initialize - TargetBufferSize: 120s
2021-04-29 01:20:15.865
Operating System: Linux version 5.4.0-72-generic (buildd@lcy01-amd64-019) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #80-Ubuntu SMP Mon Apr 12 17:35:00 UTC 2021
OS/Process: x64/x64
Emby Server version: 4.6.0.40
Operating system: Unix 5.4.0.72
Command Line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffdetect /opt/emby-server/bin/ffdetect -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -restartexitcode 3 -updatepackage emby-server-deb_{version}_amd64.deb

App: Emby Web 4.6.0.40
Firefox

...

{"Protocol":"File","Id":"8a61b3b95c2f44129016f052da8e73cd","Path":"/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.CUSTOM.FRENCH.720p.AMZN.WEB-DL.H264-FRATERNiTY.mkv","Type":"Default","Container":"mkv","Size":2935143313,"Name":"Tom.and.Jerry.2021.CUSTOM.FRENCH.720p.AMZN.WEB-DL.H264-FRATERNiTY","IsRemote":false,"RunTimeTicks":60611220000,"SupportsTranscoding":true,"SupportsDirectStream":true,"SupportsDirectPlay":true,"IsInfiniteStream":false,"RequiresOpening":false,"RequiresClosing":false,"RequiresLooping":false,"SupportsProbing":false,"MediaStreams":[{"Codec":"h264","ColorTransfer":"bt709","ColorPrimaries":"bt709","ColorSpace":"bt709","TimeBase":"1/1000","CodecTimeBase":"1001/48000","Title":"Tom.and.Jerry.2021.CUSTOM.FRENCH.720p.AMZN.WEB-DL.H264-FRATERNiTY","VideoRange":"SDR","DisplayTitle":"720p H264","NalLengthSize":"4","IsInterlaced":false,"IsAVC":true,"BitRate":3874059,"BitDepth":8,"RefFrames":1,"IsDefault":true,"IsForced":false,"Height":688,"Width":1280,"AverageFrameRate":23.976025,"RealFrameRate":23.976025,"Profile":"High","Type":"Video","AspectRatio":"14560:7869","Index":0,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Protocol":"File","PixelFormat":"yuv420p","Level":31,"IsAnamorphic":true},{"Codec":"aac","Language":"fre","TimeBase":"1/1000","CodecTimeBase":"1/48000","Title":"VFQ","DisplayTitle":"French AAC stereo (Default)","DisplayLanguage":"French","IsInterlaced":false,"ChannelLayout":"stereo","BitRate":192000,"Channels":2,"SampleRate":48000,"IsDefault":true,"IsForced":false,"Profile":"LC","Type":"Audio","Index":1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Protocol":"File"},{"Codec":"subrip","Language":"fre","TimeBase":"1/1000","CodecTimeBase":"0/1","Title":"FORCED","DisplayTitle":"French (Default SUBRIP)","DisplayLanguage":"French","IsInterlaced":false,"IsDefault":true,"IsForced":false,"Type":"Subtitle","Index":2,"IsExternal":false,"IsTextSubtitleStream":true,"SupportsExternalStream":true,"Protocol":"File"}],"Formats":[],"Bitrate":3874059,"RequiredHttpHeaders":{},"ReadAtNativeFramerate":false}

>>>>>>  User policy for Floflobel
        EnablePlaybackRemuxing: True
        EnableVideoPlaybackTranscoding: True
        EnableAudioPlaybackTranscoding: True

>>>>>>  Processing Plan
Info    Name                                        CanDoInHardware      WillDoInHardware     Reason
Info    Copy video stream                        >> False                False                Software Codec
Info    VideoInput                               >> False                False                Not a hardware decoder
Info    VideoOutput                              >> False                False                Not a hardware encoder
Info    Copy video stream                        >> False                False                Software Codec

>>>>>>  Projected Processing Formats
Info    Previous                HW-Context   Format       SW-Format           Size   Next
Info    h264                 >> -            yuv420p      yuv420p         1280x688 >>

/opt/emby-server/bin/ffmpeg -loglevel +timing -y -print_graphs_file "/var/lib/emby/logs/ffmpeg-directstream-2bae4fe5-80e1-484f-af50-22c095e00c8b_1graph.txt" -copyts -start_at_zero -f matroska,webm -noaccurate_seek -c:v:0 h264 -i "/media/storage4/films/Tom & Jerry (2021)/Tom.and.Jerry.2021.CUSTOM.FRENCH.720p.AMZN.WEB-DL.H264-FRATERNiTY.mkv" -map 0:0 -map 0:1 -sn -c:v:0 copy -bsf:v:0 h264_mp4toannexb -c:a:0 copy -metadata:s:a:0 language=fre -disposition:a:0 default -copypriorss:a:0 0 -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format mpegts -segment_list "/var/lib/emby/transcoding-temp/transcoding-temp/0F7006.m3u8" -segment_list_type m3u8 -segment_time 6 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 0 -write_header_trailer 0 -segment_write_temp 1 "/var/lib/emby/transcoding-temp/transcoding-temp/0F7006_%d.ts" -map 0:2 -map 0:0 -an -c:v:0 copy -c:s:0 webvtt -max_delay 5000000 -avoid_negative_ts disabled -f segment -map_metadata -1 -map_chapters -1 -segment_format webvtt -segment_list "/var/lib/emby/transcoding-temp/transcoding-temp/0F7006_s2.m3u8" -segment_list_type m3u8 -segment_time 6 -segment_start_number 0 -break_non_keyframes 1 -individual_header_trailer 1 -write_header_trailer 0 -write_empty_segments 1 -segment_write_temp 1 -min_frame_time 00:00:00.000 "/var/lib/emby/transcoding-temp/transcoding-temp/0F7006_s2_%d.vtt"

ssh: relocation error: ssh: symbol ENGINE_register_all_complete version OPENSSL_1_1_0 not defined in file libcrypto.so.1.1 with link time reference

...
joshuaboniface commented 3 years ago

OK it definitely looks like this is the underlying error:

ssh: relocation error: ssh: symbol ENGINE_register_all_complete version OPENSSL_1_1_0 not defined in file libcrypto.so.1.1 with link time reference

So the SSH command itself is what is not working.

rffmpeg is using a relative SSH path:

https://github.com/joshuaboniface/rffmpeg/blob/master/rffmpeg.py#L211

So this indicates to me that, somehow, you both (a) have another SSH on the $PATH while executing rffmpeg, and (b) that SSH isn't compatible with the SSL library you have installed.

Try this, both as your user (where the direct ssh command works) and as your Emby user, and let me know the output:

$ python3
>>> import subprocess
>>> import sys
>>> p = subprocess.run(['which', 'ssh'])
>>> p = subprocess.run(['ssh', '--version'], shell=False, bufsize=0, universal_newlines=True, stdin=sys.stdin, stderr=sys.stderr, stdout=sys.stdout)
>>> print(p.returncode)
$ sudo -u emby python3
[same]

I fully expect (1) is the issue, there's some random stray, incompatible, ssh program somewhere in your $PATH which the script is using.. I can add a configuration option for an explicit SSH path which would allow the explicit configuration of an SSH binary path, but getting rid of that bad one from your $PATH might be better long-term.

Floflobel commented 3 years ago

Indeed this error seems to come from an ssh problem.

I didn't understand which user you were talking about first, because all my ssh tests were done with the Emby user (except at the beginning when I forgot): Try this, both as your user (where the direct ssh command works) and as your Emby user, and let me know the output:

I added the 2 executions in doubt, one with the root user, and the second with the emby user:

root@emby:~ # python3
Python 3.7.3 (default, Jan 22 2021, 20:04:44)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> import sys
>>> p = subprocess.run(['which', 'ssh'])
/usr/bin/ssh
>>> p = subprocess.run(['ssh', '--version'], shell=False, bufsize=0, universal_newlines=True, stdin=sys.stdin, stderr=sys.stderr, stdout=sys.stdout)
unknown option -- -
usage: ssh [-46AaCfGgKkMNnqsTtVvXxYy] [-B bind_interface]
           [-b bind_address] [-c cipher_spec] [-D [bind_address:]port]
           [-E log_file] [-e escape_char] [-F configfile] [-I pkcs11]
           [-i identity_file] [-J [user@]host[:port]] [-L address]
           [-l login_name] [-m mac_spec] [-O ctl_cmd] [-o option] [-p port]
           [-Q query_option] [-R address] [-S ctl_path] [-W host:port]
           [-w local_tun[:remote_tun]] destination [command]
>>> print(p.returncode)
255
root@emby:~ # sudo -u emby python3
Python 3.7.3 (default, Jan 22 2021, 20:04:44)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> import sys
>>> p = subprocess.run(['which', 'ssh'])
/usr/bin/ssh
>>> p = subprocess.run(['ssh', '--version'], shell=False, bufsize=0, universal_newlines=True, stdin=sys.stdin, stderr=sys.stderr, stdout=sys.stdout)
unknown option -- -
usage: ssh [-46AaCfGgKkMNnqsTtVvXxYy] [-B bind_interface]
           [-b bind_address] [-c cipher_spec] [-D [bind_address:]port]
           [-E log_file] [-e escape_char] [-F configfile] [-I pkcs11]
           [-i identity_file] [-J [user@]host[:port]] [-L address]
           [-l login_name] [-m mac_spec] [-O ctl_cmd] [-o option] [-p port]
           [-Q query_option] [-R address] [-S ctl_path] [-W host:port]
           [-w local_tun[:remote_tun]] destination [command]
>>> print(p.returncode)
255

I took the liberty to modify your code because the --version command doesn't seem to exist, you have to use -V:

root@emby:~ # python3
Python 3.7.3 (default, Jan 22 2021, 20:04:44)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> import sys
>>> p = subprocess.run(['which', 'ssh'])
/usr/bin/ssh
>>> p = subprocess.run(['ssh', '-V'], shell=False, bufsize=0, universal_newlines=True, stdin=sys.stdin, stderr=sys.stderr, stdout=sys.stdout)
OpenSSH_7.9p1 Debian-10+deb10u2, OpenSSL 1.1.1d  10 Sep 2019
>>> print(p.returncode)
0
root@emby:~ # sudo -u emby python3
Python 3.7.3 (default, Jan 22 2021, 20:04:44)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> import sys
>>> p = subprocess.run(['which', 'ssh'])
/usr/bin/ssh
>>> p = subprocess.run(['ssh', '-V'], shell=False, bufsize=0, universal_newlines=True, stdin=sys.stdin, stderr=sys.stderr, stdout=sys.stdout)
OpenSSH_7.9p1 Debian-10+deb10u2, OpenSSL 1.1.1d  10 Sep 2019
>>> print(p.returncode)
0
Floflobel commented 3 years ago

I just tested your latest changes by modifying the configuration of:

    commands:
        ssh: "ssh"

by

    commands:
        ssh: "/usr/bin/ssh"

This does not change anything I still have the same error.

joshuaboniface commented 3 years ago

OK that's not what I was hoping to see, so I'm honestly not sure - I've never seen this sort of error. I'm also running that exact version of SSH, so something doesn't add up.

I was able to find https://github.com/openssl/openssl/issues/11227 which seems to point towards this being caused by having a custom OpenSSL implementation, but we're getting far beyond rffmpeg itself here. Have you made any tweaks to the system's OpenSSL, or anything of that sort? I'd suggest digging more into the specific error you get there and seeing if any of the solutions help.

Floflobel commented 3 years ago

Sorry for the long response time, but to answer you I did not make any changes to OpenSSL, it was installed via packages.

I will look and test the solutions described in the issue you gave me.

Another user has the same problem under Emby: https://emby.media/community/index.php?/topic/41443-emby-server-high-availability/&do=findComment&comment=1026494

nwilging commented 3 years ago

Chiming in here now 😃

I had the same issue as Floflobel. I was able to get around the ssh undefined symbol error by installing a portable ssh binary and configuring in the emby environment. My setup is still a work in progress, as I'm still unable to transcode remotely (likely for a different reason now). I'll continue to dig into this later today.

Here's the setup:

First, download or check this repository out onto your emby server: https://github.com/openssh/openssh-portable

If you're on ubuntu, you may need to also run:

sudo apt install -y build-essential libssl-dev libz-dev

(that can be run in your normal bash env, doesn't need to be in the emby env)

Now, create a file called test or something that you can use to drop into the "emby environment". "Emby environment" is just a shell/script env that uses the exports found in /opt/emby-server/bin/emby-ffmpeg for example.

So for example your script could look like:

#!/bin/sh

APP_DIR=/opt/emby-server

export AMDGPU_IDS=$APP_DIR/share/libdrm/amdgpu.ids
export FONTCONFIG_PATH=$APP_DIR/etc/fonts
export LD_LIBRARY_PATH=$APP_DIR/lib:$APP_DIR/extra/lib
export LIBVA_DRIVERS_PATH=$APP_DIR/extra/lib/dri
export OCL_ICD_VENDORS=$APP_DIR/extra/etc/OpenCL/vendors
export PCI_IDS_PATH=$APP_DIR/share/hwdata/pci.ids
export SSL_CERT_FILE=$APP_DIR/etc/ssl/certs/ca-certificates.crt

exec bash

Then just run it like ./test. You'll be in a new shell. cd to the directory you extracted openssh-portable to. Follow the instructions in the openssh-portable repo, and then configure it:

./configure --without-openssl-header-check

Ok now if all goes well, you can run /opt/emby-server/bin/ssh/openssh-portable/ssh -V with success (or wherever you installed ssh portable), while just ssh -V will still fail from inside the "emby env".

Modify the /etc/rffmpeg/rffmpeg.yml to reference the new ssh binary.

Now you should be able to at least run emby-ffmpeg manually and get output from your remote host's ffmpeg... Like I said I'm still having issues with my setup, but I don't think it's related to this specific problem anymore. I'll have to dig into it later today.

Sorry if this seems ramble-y, I just wanted to dump all this info before starting my day job lol.

nwilging commented 3 years ago

Success! I've gotten this working, and can transcode remotely.

You'll almost certainly need to install a portable ssh binary as detailed above. But after that, you should be good to go. Here's my full config:

rffmpeg:
    # rffmpeg state configuration - YOU SHOULD NOT ALTER THESE
    state:
        # Temporary directory to store state
        tempdir: "/run/shm/rffmpeg"

        # Filename format for state instance files
        filename: "instance_{pid}.pid"

        # Contents of the state instance file
        contents: "{host}"

    # Logging configuration
    logging:
        # Enable or disable file logging
        file: true

        # Log messages to this file - ensure the user running rffmpeg can write to it
        logfile: "/var/log/emby/rffmpeg.log"

    # Remote (SSH) configuration
    remote:
        # A YAML list of remote hosts to connect to; either direct list or name/weight supported
        hosts:
            - localhost
            - name: transcoder-1
              weight: 2   # Relative to any non-weighted hosts which have weight 1

        # The remote SSH user to connect as
        user: emby

        # A YAML list of additional SSH arguments (e.g. private keys),
        # one line per space-separated argument element.
        args: 
            - "-i"
            - "/var/lib/emby/.ssh/id_rsa"

    # Remote command configuration
    commands:
        # By default rffmpeg uses $PATH to find the "ssh" program; use this option to set a full path
        # to an SSH binary if you want to override the default.
        ssh: "/opt/emby-server/bin/ssh/openssh-portable/ssh"

        # A YAML list of prefixes to the ffmpeg command (e.g. sudo, nice, etc.),
        # one line per space-separated command element.
        pre:
            - ""

        # The (remote) ffmpeg and ffprobe command binary paths
        ffmpeg: "/usr/bin/ffmpeg"
        ffprobe: "/usr/bin/ffprobe"

        # An optional local fallback ffmpeg and ffprobe, if you wish this to be different from the above paths
        fallback_ffmpeg: "/opt/emby-server/bin/ffmpeg"
        fallback_ffprobe: "/opt/emby-server/bin/ffprobe"

What was stopping me before was permissions errors. I had to:

chown -R emby:emby /run/shm/rffmpeg
chown -R emby:emby /var/log/emby/rffmpeg.log

Then:

systemctl restart emby-server

Watching the logs, it probes the remote transcoder just fine.

Now I do think I will need to alter the fallback ffmpeg settings in the config, otherwise I believe there will be an infinite loop on the local ffmpeg binary that now points to rffmpeg.py.

I'll have to continue monitoring performance and actually attempt to watch a movie on this setup, but so far things look good.

Floflobel commented 3 years ago

Fantastic! I will try as soon as I have some time to set up OpenSSH portable.

Are you using the official version of ffmpeg? Install via repo?

nwilging commented 3 years ago

Fantastic! I will try as soon as I have some time to set up OpenSSH portable.

Are you using the official version of ffmpeg? Install via repo?

Yep, on the remote transcode server I am using the official ffmpeg version. So far it doesn't appear to cause any issues.

I also copied the original /opt/emby-server/bin/ffmpeg and ffprobe to new files such as /opt/emby-server/bin/emby-wrapper-ffmpeg, and then used those paths for the "fallback" ffmpeg paths.

Otherwise I was ending up in an infinite loop if rffmpeg chose the local transcoder.

My file setup is still a bit confusing lol. I'll try to illustrate it. Everything is in /opt/emby-server/bin:

emby-ffmpeg -> {runs rffmpeg.py directly}
ffmpeg -> linked to rffmpeg.py
ffprobe -> linked to rffmpeg.py
emby-ffprobe -> {copy of original unlinked ffprobe}
emby-wrapper-ffmpeg -> {copy of original unlinked ffmpeg}

Basically, emby needs to run the "original" ffmpeg binaries when transcoding locally. It needs to run rffmpeg as the initial entrypoint though. And emby doesn't always use emby-ffmpeg, it sometimes calls ffmpeg directly.

So, when emby begins transcoding, it hits rffmpeg.py. rffmpeg determines the host to transcode on, then calls the appropriate binary (official ffmpeg on remote host, emby-wrapper-ffmpeg and emby-ffprobe locally).

Floflobel commented 3 years ago

@nwilging Thank you very much for all the details you have provided. My rffmpeg server is finally operational.

Thanks a lot to @joshuaboniface for his help and the changes made on this script.

joshuaboniface commented 3 years ago

Thanks everyone for this, hopefully all is well. I'll close this issue out now but if anything else comes up I'm happy to reopen it!