nzbToMedia icon indicating copy to clipboard operation
nzbToMedia copied to clipboard

Published 20 hours ago • verified publisher icon clinton-hall

Exit(1) SickBeard: Failed to post-process - Returned log from SickBeard was not as expected.!

Open Sarcas666 opened this issue 4 years ago • 8 comments

Describe the bug Several of my download are getting this error. The download IS processed successfully by Medusa though. The downloaded file is in the right place and the status is downloaded.

Technical Specs

  1. Running on MacOS 10.15.7
  2. Python version : 2.7.16 and 3.8.2
  3. Download Client : SABnbzd (3.1.0)
  4. Intended Media Management (Radarr, Medusa) '....'

Note: Scripts are directly called from SABnzbd. I do not know why they keep running in python2. I tried calling a bash script with for example 'python3 <scriptname.py> ' but that gives me a lot of error about ascidians or unicodes. A different issue though. I mention it here in case you are wondering why the script still runs python2.

Expected behavior Successful download exit code, or more precise report of is wrong

Log

/Applications/nzbToMedia/eol.py:148: LifetimeWarning: Python 2.7 is no longer supported.
warnings.warn(msg, LifetimeWarning)
WARNING: Executing a script that is loading libcrypto in an unsafe way. This will fail in a future version of macOS. Set the LIBRESSL_REDIRECT_STUB_ABORT=1 in the environment to force this into an error.
[06:52:38] [INFO]::MAIN: Loading config from [/Applications/nzbToMedia/autoProcessMedia.cfg]
[06:52:38] [INFO]::ENVIRONMENT: SAB_SCRIPT: nzbToSickBeard.py
[06:52:38] [INFO]::ENVIRONMENT: SAB_AGE: 3d
[06:52:38] [INFO]::ENVIRONMENT: SAB_ORIG_NZB_GZ: /Users/<myusername>/Downloads/MediaDownloads/incompleteSABnzbd/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR/__ADMIN__/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.nzb.gz
[06:52:38] [INFO]::ENVIRONMENT: SAB_PAR2_COMMAND: /Applications/SABnzbd.app/Contents/MacOS/osx/par2/par2-sl64
[06:52:38] [INFO]::ENVIRONMENT: SAB_ENCRYPTED: 0
[06:52:38] [INFO]::ENVIRONMENT: SAB_PP_STATUS: 0
[06:52:38] [INFO]::ENVIRONMENT: SAB_ZIP_COMMAND: /usr/bin/unzip
[06:52:38] [INFO]::ENVIRONMENT: LOGNAME: <myusername>
[06:52:38] [INFO]::ENVIRONMENT: USER: <myusername>
[06:52:38] [INFO]::ENVIRONMENT: PATH: /usr/bin:/bin:/usr/sbin:/sbin
[06:52:38] [INFO]::ENVIRONMENT: HOME: /Users/<myusername>
[06:52:38] [INFO]::ENVIRONMENT: SAB_BYTES: 26937970046
[06:52:38] [INFO]::ENVIRONMENT: LANG: en_US.UTF-8
[06:52:38] [INFO]::ENVIRONMENT: SAB_DUPLICATE: 0
[06:52:38] [INFO]::ENVIRONMENT: SHELL: /bin/zsh
[06:52:38] [INFO]::ENVIRONMENT: SAB_UNWANTED_EXT: 0
[06:52:38] [INFO]::ENVIRONMENT: SAB_FAIL_MSG:
[06:52:38] [INFO]::ENVIRONMENT: SAB_NZO_ID: SABnzbd_nzo_05_cgtpv
[06:52:38] [INFO]::ENVIRONMENT: SECURITYSESSIONID: 186a5
[06:52:38] [INFO]::ENVIRONMENT: XPC_FLAGS: 0x0
[06:52:38] [INFO]::ENVIRONMENT: SAB_CAT: tv
[06:52:38] [INFO]::ENVIRONMENT: SAB_COMPLETE_DIR: /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:38] [INFO]::ENVIRONMENT: SSL_CERT_FILE: /Applications/SABnzbd.app/Contents/MacOS/certifi/cacert.pem
[06:52:38] [INFO]::ENVIRONMENT: SAB_PASSWORD:
[06:52:38] [INFO]::ENVIRONMENT: SAB_STATUS: Running
[06:52:38] [INFO]::ENVIRONMENT: SAB_7ZIP_COMMAND: /Applications/SABnzbd.app/Contents/MacOS/osx/7zip/7za
[06:52:38] [INFO]::ENVIRONMENT: SAB_BYTES_TRIED: 26937970046
[06:52:38] [INFO]::ENVIRONMENT: SSH_AUTH_SOCK: /private/tmp/com.apple.launchd.gcuY7x18Dk/Listeners
[06:52:38] [INFO]::ENVIRONMENT: SAB_AVG_BPS: 5064
[06:52:38] [INFO]::ENVIRONMENT: SAB_FILENAME: Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.nzb
[06:52:38] [INFO]::ENVIRONMENT: SAB_GROUP: alt.binaries.goonies
[06:52:38] [INFO]::ENVIRONMENT: SAB_DOWNLOAD_TIME: 4943
[06:52:38] [INFO]::ENVIRONMENT: XPC_SERVICE_NAME: org.sabnzbd.sabnzbd.87632
[06:52:38] [INFO]::ENVIRONMENT: SAB_BYTES_DOWNLOADED: 25636575023
[06:52:38] [INFO]::ENVIRONMENT: SAB_PP: 3
[06:52:38] [INFO]::ENVIRONMENT: SAB_OVERSIZED: 0
[06:52:38] [INFO]::ENVIRONMENT: SAB_PROGRAM_DIR: /Applications/SABnzbd.app/Contents/MacOS
[06:52:38] [INFO]::ENVIRONMENT: LC_ALL: en_US.UTF-8
[06:52:38] [INFO]::ENVIRONMENT: SAB_URL: https://nzbfinder.ws/getnzb?id=3a10fcbd-a6ea-45d1-8a4a-bd7be9bee7c2.nzb&r=b6801274b887c59cd2e8dc5a943cf515
[06:52:38] [INFO]::ENVIRONMENT: SAB_REPAIR: 1
[06:52:38] [INFO]::ENVIRONMENT: SAB_UNPACK: 1
[06:52:38] [INFO]::ENVIRONMENT: TMPDIR: /var/folders/5w/r2d89fbn7j18rf4yv8p928zc0000gq/T/
[06:52:38] [INFO]::ENVIRONMENT: LaunchInstanceID: A455A0F2-3AE3-4B6D-9ACC-5016D69E8F9E
[06:52:38] [INFO]::ENVIRONMENT: SAB_FAILURE_URL:
[06:52:38] [INFO]::ENVIRONMENT: SAB_PRIORITY: 0
[06:52:38] [INFO]::ENVIRONMENT: SAB_MULTIPAR_COMMAND:
[06:52:38] [INFO]::ENVIRONMENT: VERSIONER_PYTHON_VERSION: 2.7
[06:52:38] [INFO]::ENVIRONMENT: SAB_RAR_COMMAND: /Applications/SABnzbd.app/Contents/MacOS/osx/unrar/unrar
[06:52:38] [INFO]::ENVIRONMENT: __CF_USER_TEXT_ENCODING: 0x1F7:0x0:0x5
[06:52:38] [INFO]::ENVIRONMENT: SAB_VERSION: 3.1.0
[06:52:38] [INFO]::ENVIRONMENT: SAB_FINAL_NAME: Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:38] [INFO]::MAIN: Python v2.7 reached end of life 315 days ago.
[06:52:38] [WARNING]::MAIN: Please upgrade to a more recent Python version.
[06:52:38] [INFO]::MAIN: Checking database structure...
[06:52:38] [DEBUG]::MAIN: Checking Initial Schema database upgrade
[06:52:38] [DB]::MAIN: nzbtomedia.db: SELECT 1 FROM sqlite_master WHERE name = ?; with args (u'db_version',)
[06:52:38] [DB]::MAIN: nzbtomedia.db: SELECT db_version FROM db_version
[06:52:38] [DEBUG]::MAIN: InitialSchema upgrade not required
[06:52:38] [DEBUG]::MAIN: Checking if we can use git commands: "/usr/bin/git" version
[06:52:38] [DEBUG]::MAIN: Executing "/usr/bin/git" version with your shell in /Applications/nzbToMedia
[06:52:38] [DEBUG]::MAIN: git output: git version 2.24.3 (Apple Git-128)
[06:52:38] [DEBUG]::MAIN: "/usr/bin/git" version : returned successful
[06:52:38] [DEBUG]::MAIN: Using: "/usr/bin/git"
[06:52:38] [DEBUG]::MAIN: Executing "/usr/bin/git" symbolic-ref -q HEAD with your shell in /Applications/nzbToMedia
[06:52:38] [DEBUG]::MAIN: git output: refs/heads/nightly
[06:52:38] [DEBUG]::MAIN: "/usr/bin/git" symbolic-ref -q HEAD : returned successful
[06:52:38] [INFO]::MAIN: Checking if git needs an update
[06:52:38] [DEBUG]::MAIN: Executing "/usr/bin/git" rev-parse HEAD with your shell in /Applications/nzbToMedia
[06:52:38] [DEBUG]::MAIN: git output: d4d5f00a188c19732284305cff648b95ca0a7859
[06:52:38] [DEBUG]::MAIN: "/usr/bin/git" rev-parse HEAD : returned successful
[06:52:38] [DEBUG]::MAIN: Executing "/usr/bin/git" fetch origin with your shell in /Applications/nzbToMedia
[06:52:39] [DEBUG]::MAIN: git output:
[06:52:39] [DEBUG]::MAIN: "/usr/bin/git" fetch origin : returned successful
[06:52:39] [DEBUG]::MAIN: Executing "/usr/bin/git" rev-parse --verify --quiet '@{upstream}' with your shell in /Applications/nzbToMedia
[06:52:39] [DEBUG]::MAIN: git output: d4d5f00a188c19732284305cff648b95ca0a7859
[06:52:39] [DEBUG]::MAIN: "/usr/bin/git" rev-parse --verify --quiet '@{upstream}' : returned successful
[06:52:39] [DEBUG]::MAIN: Executing "/usr/bin/git" rev-list --left-right '@{upstream}'...HEAD with your shell in /Applications/nzbToMedia
[06:52:39] [DEBUG]::MAIN: git output:
[06:52:39] [DEBUG]::MAIN: "/usr/bin/git" rev-list --left-right '@{upstream}'...HEAD : returned successful
[06:52:39] [DEBUG]::MAIN: cur_commit = d4d5f00a188c19732284305cff648b95ca0a7859 % (newest_commit)= d4d5f00a188c19732284305cff648b95ca0a7859, num_commits_behind = 0, num_commits_ahead = 0
[06:52:39] [INFO]::MAIN: No update needed
[06:52:39] [INFO]::MAIN: nzbToMedia Version:d4d5f00a188c19732284305cff648b95ca0a7859 Branch:nightly (Darwin 19.6.0)
[06:52:39] [INFO]::MAIN: #########################################################
[06:52:39] [INFO]::MAIN: ## ..::[nzbToMedia.py]::.. ##
[06:52:39] [INFO]::MAIN: #########################################################
[06:52:39] [DEBUG]::MAIN: Options passed into nzbToMedia: ['/Applications/nzbToMedia/nzbToSickBeard.py', '/Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR', 'Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.nzb', 'Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR', '', 'tv', 'alt.binaries.goonies', '0', '']
[06:52:39] [INFO]::MAIN: Script triggered from SABnzbd Version 3.1.0.
[06:52:39] [DEBUG]::MAIN: Adding NZB download info for directory /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR to database
[06:52:39] [DB]::MAIN: nzbtomedia.db: UPDATE downloads SET status = ?, client_agent = ?, last_update = ?, input_id = ?, input_hash = ?, input_name = ? WHERE input_directory = ? with args [0, u'sabnzbd', 737740, u'SABnzbd_nzo_05_cgtpv', u'SABnzbd_nzo_05_cgtpv', u'Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR', u'/Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR']
[06:52:39] [DB]::MAIN: nzbtomedia.db: INSERT OR IGNORE INTO downloads (status, client_agent, last_update, input_id, input_hash, input_name) VALUES (?, ?, ?, ?, ?, ?) with args [0, u'sabnzbd', 737740, u'SABnzbd_nzo_05_cgtpv', u'SABnzbd_nzo_05_cgtpv', u'Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR']
[06:52:39] [INFO]::MAIN: Auto-detected SECTION:SickBeard
[06:52:39] [DEBUG]::MAIN: Checking for archives to extract in directory: /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:39] [INFO]::MAIN: Calling SickBeard:tv to post-process:Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:39] [DEBUG]::SERVER: Attempting to connect to server at http://localhost:8081
[06:52:39] [DEBUG]::SERVER: Server responded at http://localhost:8081
[06:52:39] [INFO]::MAIN: Attempting to auto-detect tv fork
[06:52:39] [DEBUG]::MAIN: Removing excess parameters: [u'delete', u'delete_on', u'dir', u'dirName', u'force', u'force_next', u'ignore_subs', u'is priority', u'proc_dir']
[06:52:39] [INFO]::MAIN: SickBeard:tv fork auto-detection successful ...
[06:52:39] [INFO]::MAIN: SickBeard:tv fork set to Medusa-api
[06:52:39] [INFO]::MAIN: FLATTEN: Flattening directory: /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:39] [DEBUG]::MAIN: Checking for empty folders in:/Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR
[06:52:39] [DEBUG]::MAIN: calling command: /usr/local/bin/ffprobe -v quiet -print_format json -show_format -show_streams -show_error /Applications/nzbToMedia/tests/test.mp4
[06:52:40] [INFO]::TRANSCODER: Checking [Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.mkv] for corruption, please stand by ...
[06:52:40] [DEBUG]::MAIN: calling command: /usr/local/bin/ffprobe -v quiet -print_format json -show_format -show_streams -show_error /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.mkv
[06:52:40] [INFO]::TRANSCODER: SUCCESS: [Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.mkv] has no corruption.
[06:52:40] [INFO]::SUBTITLES: Attempting to download subtitles for /Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR.mkv
[06:52:57] [POSTPROCESS]::SICKBEARD: SUCCESS: The download succeeded, sending a post-process request
[06:52:57] [DEBUG]::SICKBEARD: Opening URL: http://localhost:8081/api/<myapi>/ with params: {u'process_method': 'move', u'path': '/Users/<myusername>/Downloads/MediaDownloads/tv/Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR', u'nzbName': 'Game.of.Thrones.S03E04.And.Now.His.Watch.Is.Ended.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR', u'cmd': u'postprocess', u'failed': 0, u'return_data': 0}
[06:58:32] [ERROR]::MAIN: A problem was reported in the /Applications/nzbToMedia/nzbToSickBeard.py script.
Changing to directory: /Applications/nzbToMedia

-- Cleaning bytecode --
Removing cleanup.pyc
Removing eol.pyc
Removing libs/common/babelfish/converters/countryname.pyc
Removing libs/common/babelfish/converters/name.pyc
Removing libs/common/dogpile/cache/backends/file.pyc
Removing libs/common/subliminal/converters/shooter.pyc
Removing nzbToMedia.pyc

Removing cleanup.pyc
Removing eol.pyc
Removing libs/common/babelfish/converters/countryname.pyc
Removing libs/common/babelfish/converters/name.pyc
Removing libs/common/dogpile/cache/backends/file.pyc
Removing libs/common/subliminal/converters/shooter.pyc
Removing nzbToMedia.pyc


-- Cleaning folders: [u'libs', u'core'] --
No folders to clean

Returning to directory:  /Applications/SABnzbd.app/Contents/MacOS

-- Cleanup finished --

SickBeard: Failed to post-process - Returned log from SickBeard was not as expected.!

Sarcas666 avatar Nov 11 '20 07:11 Sarcas666

using a bash script you need to also pass all the arguments.

try python3 nzbToMedia.py "$@"

As far as the error in processing Returned log from SickBeard was not as expected take a look at Medusa logs at [06:52:57] to see if that gives any reason as to what went wrong...

clinton-hall avatar Nov 11 '20 08:11 clinton-hall

After I cleaned up all downloads en failed downloads, all new downloads seems te be processed as expected. I think my system got confused again, and started downloading things already downloaded, which gave strange errors.

About the python 3 problem (which isn’t a problem since the scripts still work with python 2 so far); I have .sh scripts doing this. Unfortunately it always errors:

Changing to directory: /Applications/nzbToMedia

-- Cleaning bytecode --
b'Removing libs/common/babelfish/converters/countryname.pyc\nRemoving libs/common/babelfish/converters/name.pyc\nRemoving libs/common/dogpile/cache/backends/file.pyc\nRemoving libs/common/subliminal/converters/shooter.pyc\nRemoving libs/common/subliminal/converters/tvsubtitles.pyc\n'
b'Removing libs/common/babelfish/converters/countryname.pyc\nRemoving libs/common/babelfish/converters/name.pyc\nRemoving libs/common/dogpile/cache/backends/file.pyc\nRemoving libs/common/subliminal/converters/shooter.pyc\nRemoving libs/common/subliminal/converters/tvsubtitles.pyc\n'

-- Cleaning folders: ['libs', 'core'] --
No folders to clean

Returning to directory:  /Applications/SABnzbd.app/Contents/MacOS

-- Cleanup finished --

Traceback (most recent call last):
File "/Applications/nzbToMedia/nzbToSickBeard.py", line 273, in <module>
result = nzbToMedia.main(sys.argv, section)
File "/Applications/nzbToMedia/nzbToMedia.py", line 885, in main
core.initialize(section)
File "/Applications/nzbToMedia/core/__init__.py", line 1024, in initialize
configure_migration()
File "/Applications/nzbToMedia/core/__init__.py", line 339, in configure_migration
if not config.migrate():
File "/Applications/nzbToMedia/core/configuration.py", line 253, in migrate
CFG_OLD.write()
File "/Applications/nzbToMedia/libs/common/configobj.py", line 2117, in write
output_bytes = output.encode(self.encoding or
UnicodeEncodeError: 'ascii' codec can't encode character '\u2022' in position 25328: ordinal not in range(128)

It is another topic though.

Thanks for your help again :)

Sarcas666 avatar Nov 17 '20 11:11 Sarcas666

That error looks like it fails doing the back-up/migration of your autoProcessMedia.cfg file. The fact that this fails in Py3 and not in Py2 is surprising... but it appears that this is trying to write as bytes type and py3 does handle this differently...

The error seems to indicate that the file has a "Bullet" point in it. So I'd look at the cfg and make sure there are no bullet points in this anywhere.

Otherwise, if you want to email your .cfg through to [email protected] I can try and test it here to see what is causing this failure in py3.

clinton-hall avatar Nov 17 '20 20:11 clinton-hall

Correct, I have some media folders starting with • bullets. It is about 1TB of data so it wil take some time to fix this without upsetting Plex/loosing all metadata. Starting right away with it!

Sarcas666 avatar Nov 18 '20 08:11 Sarcas666

interesting... What encoding does your system use to support the bullets?

The fact that this works in Py2, does mean I should be able to fix this to work in py3... I'm just not sure exactly what is required for this... I tested an updated version of configobj, but the same error occurs...

clinton-hall avatar Nov 18 '20 09:11 clinton-hall

I renamed te offending folders and changed the .cgf accordingly. No more errors 👍

“What encoding does your system use to support the bullets?” If you tell me how I can find you an answer I happily tell you :)

Running on MacOS 10.15.7. Is this an answer? [14:17:21] [INFO]::ENVIRONMENT: LC_ALL: en_US.UTF-8 or [14:17:21] [INFO]::ENVIRONMENT: __CF_USER_TEXT_ENCODING: 0x1F7:0x0:0x5 or [14:17:21] [INFO]::ENVIRONMENT: LANG: en_US.UTF-8

Sarcas666 avatar Nov 18 '20 13:11 Sarcas666

Yep. UTF-8. I did some tests but still struggling to see just where to intercept this one... basically the whole config is just passed into configobj so I believe the change needs to be made in there. As above, I tested the latest version and observed the same issue in py3.

clinton-hall avatar Nov 18 '20 20:11 clinton-hall

As said, since I removed the boletus in my watchfolder names things work fine in py3. If you want me to test something I’ll add a dummy bulleted folder somewhere just say the word :)

btw the offending line in the cfg was watch_dir = /Volumes/Media\ 2/Media/•\ Clips/New in case this gives you any insight...

Sarcas666 avatar Nov 20 '20 08:11 Sarcas666