mdhiggins / sickbeard_mp4_automator

Automatically convert video files to a standardized format with metadata tagging to create a beautiful and uniform media library
MIT License
1.52k stars 201 forks source link

SABnzbd failing with or without hwaccels enabled #1306

Closed morpheus2n2 closed 4 years ago

morpheus2n2 commented 4 years ago

Making this its own issue now as it is presenting much frustration now, Sorry.

SABnzbd has in the last day started throwing up errors, I have done a fresh download/install of the script and also re-setup the autoprocess.ini and still run in to the same problems. When SAB finishes the download the second (as in immediately there's no eclipsed time at all) it starts running the script it will display SystemExit: 1

The SMA log will show

2020-08-19 05:16:42 - resources.mediaprocessor - INFO - Starting conversion.
2020-08-19 05:16:42 - resources.mediaprocessor - INFO - FFmpeg command:
2020-08-19 05:16:42 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:16:42 - resources.mediaprocessor - INFO - C:\ffmpeg\bin\ffmpeg.exe -fix_sub_duration -hwaccel dxva2 -i D:\Downloads\Completed\Jimmy.Kimmel.2020.08.17.Reese.Witherspoon.REPACK.720p.WEB.h264-ROBOTS\283db0990c8e4712a510e276ca507116.mkv -vcodec hevc_nvenc -map 0:0 -field_order progressive -vb 1500k -metadata:s:v BPS=1500000 -metadata:s:v BPS-eng=1500000 -metadata:s:v title=HD -level 5.1 -tag:v hvc1 -c:a:0 copy -map 0:1 -metadata:s:a:0 title=Stereo -metadata:s:a:0 language=eng -disposition:a:0 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -c:s:0 mov_text -map 0:2 -metadata:s:s:0 title= -metadata:s:s:0 language=eng -disposition:s:0 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -f mp4 -threads 0 -metadata:g encoding_tool=SMA -y D:\Downloads\Completed\Jimmy.Kimmel.2020.08.17.Reese.Witherspoon.REPACK.720p.WEB.h264-ROBOTS\283db0990c8e4712a510e276ca507116.mp4
2020-08-19 05:16:42 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:16:43 - resources.mediaprocessor - ERROR - Unexpected exception during conversion.
Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1418, in convert
progressOutput(timecode, debug)
File "C:\Converter\SABPostProcess.py", line 29, in progressOutput
print("%s%" % timecode)
ValueError: incomplete format
2020-08-19 05:16:43 - resources.mediaprocessor - ERROR - Error restoring original inputfile after FFMPEG error.
Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1418, in convert
progressOutput(timecode, debug)
File "C:\Converter\SABPostProcess.py", line 29, in progressOutput
print("%s%" % timecode)
ValueError: incomplete format

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1447, in convert
os.rename(inputfile, originalinputfile)
PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'D:\\Downloads\\Completed\\Jimmy.Kimmel.2020.08.17.Reese.Witherspoon.REPACK.720p.WEB.h264-ROBOTS\\283db0990c8e4712a510e276ca507116.mkv' -> 'D:\\Downloads\\Completed\\Jimmy.Kimmel.2020.08.17.Reese.Witherspoon.REPACK.720p.WEB.h264-ROBOTS\\283db0990c8e4712a510e276ca507116.mkv'
2020-08-19 05:16:43 - SABPostProcess - ERROR - Converting file failed D:\Downloads\Completed\Jimmy.Kimmel.2020.08.17.Reese.Witherspoon.REPACK.720p.WEB.h264-ROBOTS\283db0990c8e4712a510e276ca507116.mkv.
2020-08-19 05:16:43 - SABPostProcess - ERROR - No valid files found for conversion in download, aborting.
2020-08-19 05:16:43 - SABPostProcess - ERROR - Unexpected exception.
Traceback (most recent call last):
File "C:\Converter\SABPostProcess.py", line 80, in <module>
sys.exit(1)
SystemExit: 1

^^This is with hwaccels.

2020-08-19 05:19:56 - resources.mediaprocessor - INFO - Starting conversion.
2020-08-19 05:19:56 - resources.mediaprocessor - INFO - FFmpeg command:
2020-08-19 05:19:56 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:19:56 - resources.mediaprocessor - INFO - C:\ffmpeg\bin\ffmpeg.exe -fix_sub_duration -i D:\Downloads\Completed\The.Fugitive.2020.S01E13.When.Mike.Met.Colin.1080p.WEB-DL.AAC2.0.H.264-WELP\b3c850eab721439b9d525a3542ac7abc.mkv -vcodec hevc_nvenc -map 0:0 -field_order progressive -vb 1500k -metadata:s:v BPS=1500000 -metadata:s:v BPS-eng=1500000 -metadata:s:v title=FHD -level 5.1 -tag:v hvc1 -c:a:0 copy -map 0:1 -metadata:s:a:0 title=Stereo -metadata:s:a:0 language=eng -disposition:a:0 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -c:s:0 mov_text -map 0:2 -metadata:s:s:0 title= -metadata:s:s:0 language=eng -disposition:s:0 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -c:s:1 mov_text -map 0:3 -metadata:s:s:1 title= -metadata:s:s:1 language=eng -disposition:s:1 -default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -f mp4 -threads 0 -metadata:g encoding_tool=SMA -y D:\Downloads\Completed\The.Fugitive.2020.S01E13.When.Mike.Met.Colin.1080p.WEB-DL.AAC2.0.H.264-WELP\b3c850eab721439b9d525a3542ac7abc.mp4
2020-08-19 05:19:56 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:19:57 - resources.mediaprocessor - ERROR - Unexpected exception during conversion.
Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1418, in convert
progressOutput(timecode, debug)
File "C:\Converter\SABPostProcess.py", line 29, in progressOutput
print("%s%" % timecode)
ValueError: incomplete format
2020-08-19 05:19:57 - resources.mediaprocessor - ERROR - Error restoring original inputfile after FFMPEG error.
Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1418, in convert
progressOutput(timecode, debug)
File "C:\Converter\SABPostProcess.py", line 29, in progressOutput
print("%s%" % timecode)
ValueError: incomplete format

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "C:\Converter\resources\mediaprocessor.py", line 1447, in convert
os.rename(inputfile, originalinputfile)
PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'D:\\Downloads\\Completed\\The.Fugitive.2020.S01E13.When.Mike.Met.Colin.1080p.WEB-DL.AAC2.0.H.264-WELP\\b3c850eab721439b9d525a3542ac7abc.mkv' -> 'D:\\Downloads\\Completed\\The.Fugitive.2020.S01E13.When.Mike.Met.Colin.1080p.WEB-DL.AAC2.0.H.264-WELP\\b3c850eab721439b9d525a3542ac7abc.mkv'
2020-08-19 05:19:57 - SABPostProcess - ERROR - Converting file failed D:\Downloads\Completed\The.Fugitive.2020.S01E13.When.Mike.Met.Colin.1080p.WEB-DL.AAC2.0.H.264-WELP\b3c850eab721439b9d525a3542ac7abc.mkv.
2020-08-19 05:19:57 - SABPostProcess - ERROR - No valid files found for conversion in download, aborting.
2020-08-19 05:19:57 - SABPostProcess - ERROR - Unexpected exception.
Traceback (most recent call last):
File "C:\Converter\SABPostProcess.py", line 80, in <module>
sys.exit(1)
SystemExit: 1

^^This is without. I have tried running this with and without hwaccels enabled, always the same result I am running FFMpeg version ffmpeg-20200816-5df9724-win64-static.zip All was fine but since installing Nvidia Drivers 452.06 I have noticed this problem!

The part that I find interesting is "resources.mediaprocessor - ERROR - Error restoring original inputfile after FFMPEG error." As for the permission thing its because the file is in use however I can not find how by what other than ffmpeg

Really sorry to keep bothering you, just can't work out why even with a new download its suddenly stop working correctly after running fine for over 2 years.

morpheus2n2 commented 4 years ago

Just wanted to add that I also get this even when using h264 and removing all traces of HW capabilities from the autoprocess.

What makes it interesting is Deluge works perfectly fine while this is all going on, its just SAB 😦

2020-08-19 05:59:27 - resources.mediaprocessor - INFO - Starting conversion.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Input directory: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg].
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - File name: Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Input extension: mkv.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output directory: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output extension: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output file: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mp4.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Input directory: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg].
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - File name: Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Input extension: mkv.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output directory: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output extension: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Output file: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mp4.
2020-08-19 05:59:27 - resources.mediaprocessor - DEBUG - Final output file: D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mp4.
2020-08-19 05:59:27 - resources.mediaprocessor - INFO - FFmpeg command:
2020-08-19 05:59:27 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:59:27 - resources.mediaprocessor - INFO - C:\ffmpeg\bin\ffmpeg.exe -fix_sub_duration -hwaccel dxva2 -i D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]/Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mkv -vcodec hevc_nvenc -map 0:0 -field_order progressive -vb 1500k -metadata:s:v BPS=1500000 -metadata:s:v BPS-eng=1500000 -metadata:s:v title=FHD -level 5.1 -tag:v hvc1 -c:a:0 aac -map 0:1 -ac:a:0 2 -b:a:0 256k -metadata:s:a:0 BPS=256000 -metadata:s:a:0 BPS-eng=256000 -metadata:s:a:0 title=Stereo -metadata:s:a:0 language=eng -disposition:a:0 -default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -strict experimental -c:a:1 aac -map 0:1 -ac:a:1 6 -b:a:1 768k -metadata:s:a:1 BPS=768000 -metadata:s:a:1 BPS-eng=768000 -metadata:s:a:1 title=5.1 Channel -metadata:s:a:1 language=eng -disposition:a:1 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -strict experimental -c:s:0 mov_text -map 0:2 -metadata:s:s:0 title= -metadata:s:s:0 language=eng -disposition:s:0 +default-dub-original-comment-lyrics-karaoke-forced-hearing_impaired-visual_impaired-captions -f mp4 -threads 0 -metadata:g encoding_tool=SMA -y D:\Downloads\To Convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEBRip.DDP5.1.x264-NTb[rarbg]-convert\Lovecraft.Country.S01E01.Sundown.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mp4
2020-08-19 05:59:28 - resources.mediaprocessor - INFO - ======================
2020-08-19 05:59:30 - resources.mediaprocessor - DEBUG - frame=    2 fps=1.9 q=0.0 size=       0kB time=00:00:00.69 bitrate=   0.5kbits/s speed=0.67x
2020-08-19 05:59:30 - resources.mediaprocessor - DEBUG - frame=   45 fps= 29 q=30.0 size=       0kB time=00:00:02.72 bitrate=   0.1kbits/s speed=1.75x
2020-08-19 05:59:31 - resources.mediaprocessor - DEBUG - frame=   83 fps= 40 q=31.0 size=       0kB time=00:00:04.19 bitrate=   0.1kbits/s speed=2.04x
2020-08-19 05:59:31 - resources.mediaprocessor - DEBUG - frame=  113 fps= 44 q=31.0 size=     256kB time=00:00:05.36 bitrate= 390.8kbits/s speed= 2.1x
2020-08-19 05:59:32 - resources.mediaprocessor - DEBUG - frame=  147 fps= 48 q=30.0 size=     256kB time=00:00:06.71 bitrate= 312.6kbits/s speed=2.19x
2020-08-19 05:59:32 - resources.mediaprocessor - DEBUG - frame=  176 fps= 49 q=27.0 size=    1024kB time=00:00:07.84 bitrate=1069.8kbits/s speed= 2.2x
2020-08-19 05:59:33 - resources.mediaprocessor - DEBUG - frame=  205 fps= 50 q=27.0 size=    1024kB time=00:00:09.24 bitrate= 907.0kbits/s speed=2.27x
2020-08-19 05:59:33 - resources.mediaprocessor - DEBUG - frame=  233 fps= 51 q=28.0 size=    1280kB time=00:00:10.46 bitrate=1002.0kbits/s speed=2.29x
2020-08-19 05:59:34 - resources.mediaprocessor - DEBUG - frame=  271 fps= 53 q=28.0 size=    1280kB time=00:00:11.93 bitrate= 878.4kbits/s speed=2.35x
morpheus2n2 commented 4 years ago

Ok @mdhiggins I have found the problem and unfortunately it is something you have changed in the code in the last 9 days, luckily I have your script running on a different machine going through all my unsorted media, I last updated the script on it on 10/08/2020 at around 4pm GMT, I have just pulled this on over to my main downloading machine and ran SAB, just gone through 2 downloads absolutely perfect, one with all HW enabled and one without nether spat out a error.

Not sure if this helps you at all but it may give you a clue as to what's going on

mdhiggins commented 4 years ago

a84bb793afaa2bb8ca33d24ace055ba57dd6c37c

That should fix it

morpheus2n2 commented 4 years ago

Cool, will test this in a bit and let you know :D

morpheus2n2 commented 4 years ago

Yep all seems to be working now awesome stuff :D