github/nzbToMedia
1
0
Fork 0
mirror of https://github.com/clinton-hall/nzbToMedia.git synced 2025-08-21 05:43:16 -07:00
Code Issues Projects Releases Packages Wiki Activity Actions

Add standard library logging

Browse source
This commit is contained in:
Labrys of Knossos 2022-12-16 19:40:39 -05:00
commit 2f1989498d
43 changed files with 861 additions and 1449 deletions
Download patch file Download diff file Expand all files Collapse all files

90
TorrentToMedia.py
View file

@ -1,4 +1,5 @@
import datetime
import logging
import os
import sys
@ -11,6 +12,9 @@ from nzb2media.user_scripts import external_script
from nzb2media.utils.encoding import char_replace, convert_to_ascii
from nzb2media.utils.links import replace_links
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process_torrent(input_directory, input_name, input_category, input_hash, input_id, client_agent):
status = 1 # 1 = failed | 0 = success
@ -18,7 +22,7 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
found_file = 0
if client_agent != 'manual' and not nzb2media.DOWNLOAD_INFO:
logger.debug(f'Adding TORRENT download info for directory {input_directory} to database')
log.debug(f'Adding TORRENT download info for directory {input_directory} to database')
my_db = main_db.DBConnection()
@ -42,7 +46,7 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
}
my_db.upsert('downloads', new_value_dict, control_value_dict)
logger.debug(f'Received Directory: {input_directory} | Name: {input_name} | Category: {input_category}')
log.debug(f'Received Directory: {input_directory} | Name: {input_name} | Category: {input_category}')
# Confirm the category by parsing directory structure
input_directory, input_name, input_category, root = nzb2media.category_search(
@ -54,30 +58,30 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
usercat = input_category
logger.debug(f'Determined Directory: {input_directory} | Name: {input_name} | Category: {input_category}')
log.debug(f'Determined Directory: {input_directory} | Name: {input_name} | Category: {input_category}')
# auto-detect section
section = nzb2media.CFG.findsection(input_category).isenabled()
if section is None: #Check for user_scripts for 'ALL' and 'UNCAT'
if section is None: # Check for user_scripts for 'ALL' and 'UNCAT'
if usercat in nzb2media.CATEGORIES:
section = nzb2media.CFG.findsection('ALL').isenabled()
usercat = 'ALL'
else:
section = nzb2media.CFG.findsection('UNCAT').isenabled()
usercat = 'UNCAT'
if section is None: # We haven't found any categories to process.
logger.error(f'Category:[{input_category}] is not defined or is not enabled. Please rename it or ensure it is enabled for the appropriate section in your autoProcessMedia.cfg and try again.')
if section is None: # We haven't found any categories to process.
log.error(f'Category:[{input_category}] is not defined or is not enabled. Please rename it or ensure it is enabled for the appropriate section in your autoProcessMedia.cfg and try again.')
return [-1, '']
if len(section) > 1:
logger.error(f'Category:[{usercat}] is not unique, {section.keys()} are using it. Please rename it or disable all other sections using the same category name in your autoProcessMedia.cfg and try again.')
log.error(f'Category:[{usercat}] is not unique, {section.keys()} are using it. Please rename it or disable all other sections using the same category name in your autoProcessMedia.cfg and try again.')
return [-1, '']
if section:
section_name = section.keys()[0]
logger.info(f'Auto-detected SECTION:{section_name}')
log.info(f'Auto-detected SECTION:{section_name}')
else:
logger.error(f'Unable to locate a section with subsection:{input_category} enabled in your autoProcessMedia.cfg, exiting!')
log.error(f'Unable to locate a section with subsection:{input_category} enabled in your autoProcessMedia.cfg, exiting!')
return [-1, '']
section = dict(section[section_name][usercat]) # Type cast to dict() to allow effective usage of .get()
@ -110,13 +114,13 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
if output_destination in input_directory:
output_destination = input_directory
logger.info(f'Output directory set to: {output_destination}')
log.info(f'Output directory set to: {output_destination}')
if nzb2media.SAFE_MODE and output_destination == nzb2media.TORRENT_DEFAULT_DIRECTORY:
logger.error(f'The output directory:[{input_directory}] is the Download Directory. Edit outputDirectory in autoProcessMedia.cfg. Exiting')
log.error(f'The output directory:[{input_directory}] is the Download Directory. Edit outputDirectory in autoProcessMedia.cfg. Exiting')
return [-1, '']
logger.debug(f'Scanning files in directory: {input_directory}')
log.debug(f'Scanning files in directory: {input_directory}')
if section_name in ['HeadPhones', 'Lidarr']:
nzb2media.NOFLATTEN.extend(
@ -131,9 +135,9 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
input_files = nzb2media.list_media_files(input_directory, other=True, otherext=extensions)
if len(input_files) == 0 and os.path.isfile(input_directory):
input_files = [input_directory]
logger.debug(f'Found 1 file to process: {input_directory}')
log.debug(f'Found 1 file to process: {input_directory}')
else:
logger.debug(f'Found {len(input_files)} files in {input_directory}')
log.debug(f'Found {len(input_files)} files in {input_directory}')
for inputFile in input_files:
file_path = os.path.dirname(inputFile)
file_name, file_ext = os.path.splitext(os.path.basename(inputFile))
@ -145,16 +149,16 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
target_file = nzb2media.os.path.join(
nzb2media.os.path.join(output_destination, os.path.basename(file_path)), full_file_name,
)
logger.debug(f'Setting outputDestination to {os.path.dirname(target_file)} to preserve folder structure')
log.debug(f'Setting outputDestination to {os.path.dirname(target_file)} to preserve folder structure')
if root == 1:
if not found_file:
logger.debug(f'Looking for {input_name} in: {inputFile}')
log.debug(f'Looking for {input_name} in: {inputFile}')
if any([
nzb2media.sanitize_name(input_name) in nzb2media.sanitize_name(inputFile),
nzb2media.sanitize_name(file_name) in nzb2media.sanitize_name(input_name),
]):
found_file = True
logger.debug(f'Found file {full_file_name} that matches Torrent Name {input_name}')
log.debug(f'Found file {full_file_name} that matches Torrent Name {input_name}')
else:
continue
@ -163,10 +167,10 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
ctime_lapse = now - datetime.datetime.fromtimestamp(os.path.getctime(inputFile))
if not found_file:
logger.debug('Looking for files with modified/created dates less than 5 minutes old.')
log.debug('Looking for files with modified/created dates less than 5 minutes old.')
if (mtime_lapse < datetime.timedelta(minutes=5)) or (ctime_lapse < datetime.timedelta(minutes=5)):
found_file = True
logger.debug(f'Found file {full_file_name} with date modified/created less than 5 minutes ago.')
log.debug(f'Found file {full_file_name} with date modified/created less than 5 minutes ago.')
else:
continue # This file has not been recently moved or created, skip it
@ -175,12 +179,12 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
nzb2media.copy_link(inputFile, target_file, nzb2media.USE_LINK)
nzb2media.remove_read_only(target_file)
except Exception:
logger.error(f'Failed to link: {inputFile} to {target_file}')
log.error(f'Failed to link: {inputFile} to {target_file}')
input_name, output_destination = convert_to_ascii(input_name, output_destination)
if extract == 1:
logger.debug(f'Checking for archives to extract in directory: {input_directory}')
log.debug(f'Checking for archives to extract in directory: {input_directory}')
nzb2media.extract_files(input_directory, output_destination, keep_archive)
if input_category not in nzb2media.NOFLATTEN:
@ -193,20 +197,20 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
nzb2media.list_media_files(output_destination, media=True, audio=False, meta=False, archives=False),
)
if num_videos > 0:
logger.info(f'Found {num_videos} media files in {output_destination}')
log.info(f'Found {num_videos} media files in {output_destination}')
status = 0
elif extract != 1:
logger.info(f'Found no media files in {output_destination}. Sending to {section_name} to process')
log.info(f'Found no media files in {output_destination}. Sending to {section_name} to process')
status = 0
else:
logger.warning(f'Found no media files in {output_destination}')
log.warning(f'Found no media files in {output_destination}')
# Only these sections can handling failed downloads
# so make sure everything else gets through without the check for failed
if section_name not in ['CouchPotato', 'Radarr', 'SickBeard', 'SiCKRAGE', 'NzbDrone', 'Sonarr', 'Watcher3']:
status = 0
logger.info(f'Calling {section_name}:{usercat} to post-process:{input_name}')
log.info(f'Calling {section_name}:{usercat} to post-process:{input_name}')
if nzb2media.TORRENT_CHMOD_DIRECTORY:
nzb2media.rchmod(output_destination, nzb2media.TORRENT_CHMOD_DIRECTORY)
@ -245,12 +249,12 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
if result.status_code != 0:
if not nzb2media.TORRENT_RESUME_ON_FAILURE:
logger.error(
log.error(
'A problem was reported in the autoProcess* script. '
'Torrent won\'t resume seeding (settings)',
)
elif client_agent != 'manual':
logger.error(
log.error(
'A problem was reported in the autoProcess* script. '
'If torrent was paused we will resume seeding',
)
@ -263,10 +267,10 @@ def process_torrent(input_directory, input_name, input_category, input_hash, inp
# remove torrent
if nzb2media.USE_LINK == 'move-sym' and not nzb2media.DELETE_ORIGINAL == 1:
logger.debug(f'Checking for sym-links to re-direct in: {input_directory}')
log.debug(f'Checking for sym-links to re-direct in: {input_directory}')
for dirpath, _, files in os.walk(input_directory):
for file in files:
logger.debug(f'Checking symlink: {os.path.join(dirpath, file)}')
log.debug(f'Checking symlink: {os.path.join(dirpath, file)}')
replace_links(os.path.join(dirpath, file))
nzb2media.remove_torrent(client_agent, input_hash, input_id, input_name)
@ -285,12 +289,12 @@ def main(args):
# clientAgent for Torrents
client_agent = nzb2media.TORRENT_CLIENT_AGENT
logger.info('#########################################################')
logger.info(f'## ..::[{os.path.basename(__file__)}]::.. ##')
logger.info('#########################################################')
log.info('#########################################################')
log.info(f'## ..::[{os.path.basename(__file__)}]::.. ##')
log.info('#########################################################')
# debug command line options
logger.debug(f'Options passed into TorrentToMedia: {args}')
log.debug(f'Options passed into TorrentToMedia: {args}')
# Post-Processing Result
result = ProcessResult(
@ -301,33 +305,33 @@ def main(args):
try:
input_directory, input_name, input_category, input_hash, input_id = nzb2media.parse_args(client_agent, args)
except Exception:
logger.error('There was a problem loading variables')
log.error('There was a problem loading variables')
return -1
if input_directory and input_name and input_hash and input_id:
result = process_torrent(input_directory, input_name, input_category, input_hash, input_id, client_agent)
elif nzb2media.TORRENT_NO_MANUAL:
logger.warning('Invalid number of arguments received from client, and no_manual set')
log.warning('Invalid number of arguments received from client, and no_manual set')
else:
# Perform Manual Post-Processing
logger.warning('Invalid number of arguments received from client, Switching to manual run mode ...')
log.warning('Invalid number of arguments received from client, Switching to manual run mode ...')
for section, subsections in nzb2media.SECTIONS.items():
for subsection in subsections:
if not nzb2media.CFG[section][subsection].isenabled():
continue
for dir_name in nzb2media.get_dirs(section, subsection, link='hard'):
logger.info(f'Starting manual run for {section}:{subsection} - Folder:{dir_name}')
log.info(f'Starting manual run for {section}:{subsection} - Folder:{dir_name}')
logger.info(f'Checking database for download info for {os.path.basename(dir_name)} ...')
log.info(f'Checking database for download info for {os.path.basename(dir_name)} ...')
nzb2media.DOWNLOAD_INFO = nzb2media.get_download_info(os.path.basename(dir_name), 0)
if nzb2media.DOWNLOAD_INFO:
client_agent = nzb2media.DOWNLOAD_INFO[0]['client_agent'] or 'manual'
input_hash = nzb2media.DOWNLOAD_INFO[0]['input_hash'] or ''
input_id = nzb2media.DOWNLOAD_INFO[0]['input_id'] or ''
logger.info(f'Found download info for {os.path.basename(dir_name)}, setting variables now ...')
log.info(f'Found download info for {os.path.basename(dir_name)}, setting variables now ...')
else:
logger.info(f'Unable to locate download info for {os.path.basename(dir_name)}, continuing to try and process this release ...')
log.info(f'Unable to locate download info for {os.path.basename(dir_name)}, continuing to try and process this release ...')
client_agent = 'manual'
input_hash = ''
input_id = ''
@ -342,13 +346,13 @@ def main(args):
client_agent,
)
if results.status_code != 0:
logger.error(f'A problem was reported when trying to perform a manual run for {section}:{subsection}.')
log.error(f'A problem was reported when trying to perform a manual run for {section}:{subsection}.')
result = results
if result.status_code == 0:
logger.info(f'The {args[0]} script completed successfully.')
log.info(f'The {args[0]} script completed successfully.')
else:
logger.error(f'A problem was reported in the {args[0]} script.')
log.error(f'A problem was reported in the {args[0]} script.')
del nzb2media.MYAPP
return result.status_code

65
nzb2media/__init__.py
View file

@ -2,6 +2,7 @@ from __future__ import annotations
import itertools
import locale
import logging
import os
import pathlib
import platform
@ -11,6 +12,9 @@ import sys
import time
import typing
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
try:
import win32event
except ImportError:
@ -417,9 +421,7 @@ def configure_migration():
# run migrate to convert old cfg to new style cfg plus fix any cfg missing values/options.
if not config.migrate():
logger.error(
f'Unable to migrate config file {CONFIG_FILE}, exiting ...',
)
log.error(f'Unable to migrate config file {CONFIG_FILE}, exiting ...')
if 'NZBOP_SCRIPTDIR' in os.environ:
pass # We will try and read config from Environment.
else:
@ -430,7 +432,7 @@ def configure_migration():
CFG = config.addnzbget()
else: # load newly migrated config
logger.info(f'Loading config from [{CONFIG_FILE}]')
log.info(f'Loading config from [{CONFIG_FILE}]')
CFG = config()
@ -448,7 +450,7 @@ def configure_logging_part_2():
if LOG_ENV:
for item in os.environ:
logger.info(f'{item}: {os.environ[item]}', 'ENVIRONMENT')
log.info(f'{item}: {os.environ[item]}')
def configure_general():
@ -493,7 +495,7 @@ def configure_updates():
# Check for updates via GitHUB
if version_checker.check_for_new_version() and AUTO_UPDATE:
logger.info('Auto-Updating nzbToMedia, Please wait ...')
log.info('Auto-Updating nzbToMedia, Please wait ...')
if version_checker.update():
# restart nzbToMedia
try:
@ -502,14 +504,10 @@ def configure_updates():
pass
restart()
else:
logger.error(
'Update failed, not restarting. Check your log for more information.',
)
log.error('Update failed, not restarting. Check your log for more information.')
# Set Current Version
logger.info(
f'nzbToMedia Version:{NZBTOMEDIA_VERSION} Branch:{GIT_BRANCH} ({platform.system()} {platform.release()})',
)
log.info(f'nzbToMedia Version:{NZBTOMEDIA_VERSION} Branch:{GIT_BRANCH} ({platform.system()} {platform.release()})')
def configure_wake_on_lan():
@ -1424,22 +1422,14 @@ def configure_utility_locations():
if not (os.path.isfile(FFMPEG)): # problem
FFMPEG = None
logger.warning(
'Failed to locate ffmpeg.exe. Transcoding disabled!',
)
logger.warning(
'Install ffmpeg with x264 support to enable this feature ...',
)
log.warning('Failed to locate ffmpeg.exe. Transcoding disabled!')
log.warning('Install ffmpeg with x264 support to enable this feature ...')
if not (os.path.isfile(FFPROBE)):
FFPROBE = None
if CHECK_MEDIA:
logger.warning(
'Failed to locate ffprobe.exe. Video corruption detection disabled!',
)
logger.warning(
'Install ffmpeg with x264 support to enable this feature ...',
)
log.warning('Failed to locate ffprobe.exe. Video corruption detection disabled!')
log.warning('Install ffmpeg with x264 support to enable this feature ...')
else:
if SYS_PATH:
@ -1475,9 +1465,7 @@ def configure_utility_locations():
pass
if not SEVENZIP:
SEVENZIP = None
logger.warning(
'Failed to locate 7zip. Transcoding of disk images and extraction of .7z files will not be possible!',
)
log.warning('Failed to locate 7zip. Transcoding of disk images and extraction of .7z files will not be possible!')
try:
PAR2CMD = (
subprocess.Popen(['which', 'par2'], stdout=subprocess.PIPE)
@ -1489,9 +1477,7 @@ def configure_utility_locations():
pass
if not PAR2CMD:
PAR2CMD = None
logger.warning(
'Failed to locate par2. Repair and rename using par files will not be possible!',
)
log.warning('Failed to locate par2. Repair and rename using par files will not be possible!')
if os.path.isfile(os.path.join(FFMPEG_PATH, 'ffmpeg')) or os.access(
os.path.join(FFMPEG_PATH, 'ffmpeg'),
os.X_OK,
@ -1528,10 +1514,8 @@ def configure_utility_locations():
pass
if not FFMPEG:
FFMPEG = None
logger.warning('Failed to locate ffmpeg. Transcoding disabled!')
logger.warning(
'Install ffmpeg with x264 support to enable this feature ...',
)
log.warning('Failed to locate ffmpeg. Transcoding disabled!')
log.warning('Install ffmpeg with x264 support to enable this feature ...')
if os.path.isfile(os.path.join(FFMPEG_PATH, 'ffprobe')) or os.access(
os.path.join(FFMPEG_PATH, 'ffprobe'),
@ -1570,14 +1554,8 @@ def configure_utility_locations():
if not FFPROBE:
FFPROBE = None
if CHECK_MEDIA:
logger.warning(
'Failed to locate ffprobe. Video corruption detection disabled!',
)
logger.warning(
'Install ffmpeg with x264 support to enable this feature ...',
)
log.warning('Failed to locate ffprobe. Video corruption detection disabled!')
log.warning('Install ffmpeg with x264 support to enable this feature ...')
def initialize(section=None):
@ -1590,9 +1568,6 @@ def initialize(section=None):
configure_process()
configure_locale()
# init logging
logger.ntm_log_instance.init_logging()
configure_migration()
configure_logging_part_2()

29
nzb2media/auto_process/books.py
View file

@ -1,5 +1,7 @@
from __future__ import annotations
import logging
import requests
import nzb2media
@ -9,6 +11,9 @@ from nzb2media.utils.encoding import convert_to_ascii
from nzb2media.utils.network import server_responding
from nzb2media.utils.paths import remote_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -44,7 +49,7 @@ def process(
# Begin processing
url = nzb2media.utils.common.create_url(scheme, host, port, web_root)
if not server_responding(url):
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -57,41 +62,39 @@ def process(
'dir': remote_dir(dir_name) if remote_path else dir_name,
}
logger.debug(f'Opening URL: {url} with params: {params}', section)
log.debug(f'Opening URL: {url} with params: {params}')
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 300))
response = requests.get(url, params=params, verify=False, timeout=(30, 300))
except requests.ConnectionError:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
)
logger.postprocess(f'{r.text}', section)
log.debug(response.text)
if r.status_code not in [
if response.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {response.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status '
f'{r.status_code}',
f'{response.status_code}',
)
elif r.text == 'OK':
logger.postprocess(
elif response.text == 'OK':
log.debug(
f'SUCCESS: ForceProcess for {dir_name} has been started in LazyLibrarian',
section,
)
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
else:
logger.error(
log.error(
f'FAILED: ForceProcess of {dir_name} has Failed in LazyLibrarian',
section,
)
return ProcessResult.failure(
f'{section}: Failed to post-process - Returned log from {section} '

24
nzb2media/auto_process/comics.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import requests
@ -11,6 +12,9 @@ from nzb2media.utils.encoding import convert_to_ascii
from nzb2media.utils.network import server_responding
from nzb2media.utils.paths import remote_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -48,7 +52,7 @@ def process(
# Begin processing
url = nzb2media.utils.common.create_url(scheme, host, port, web_root)
if not server_responding(url):
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -72,13 +76,13 @@ def process(
success = False
logger.debug(f'Opening URL: {url}', section)
log.debug(f'Opening URL: {url}')
try:
r = requests.post(
url, params=params, stream=True, verify=False, timeout=(30, 300),
)
except requests.ConnectionError:
logger.error('Unable to open URL', section)
log.error('Unable to open URL')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
@ -88,7 +92,7 @@ def process(
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {r.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status '
f'{r.status_code}',
@ -96,21 +100,19 @@ def process(
for line in r.text.split('\n'):
if line:
logger.postprocess(line, section)
log.debug(line)
if 'Post Processing SUCCESSFUL' in line:
success = True
if success:
logger.postprocess(
'SUCCESS: This issue has been processed successfully', section,
)
log.debug('SUCCESS: This issue has been processed successfully')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
else:
logger.warning(
'The issue does not appear to have successfully processed. Please check your Logs',
section,
log.warning(
'The issue does not appear to have successfully processed. '
'Please check your Logs',
)
return ProcessResult.failure(
f'{section}: Failed to post-process - Returned log from '

19
nzb2media/auto_process/common.py
View file

@ -1,9 +1,13 @@
from __future__ import annotations
import logging
import typing
import requests
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class ProcessResult(typing.NamedTuple):
status_code: int
@ -39,23 +43,22 @@ def command_complete(url, params, headers, section):
timeout=(30, 60),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL: {url}', section)
log.error(f'Unable to open URL: {url}')
return None
if r.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {r.status_code}')
return None
else:
try:
return r.json()['status']
except (ValueError, KeyError):
# ValueError catches simplejson's JSONDecodeError and json's ValueError
logger.error(
f'{section} did not return expected json data.', section,
)
# ValueError catches simplejson's JSONDecodeError and
# json's ValueError
log.error(f'{section} did not return expected json data.')
return None
@ -70,14 +73,14 @@ def completed_download_handling(url2, headers, section='MAIN'):
timeout=(30, 60),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL: {url2}', section)
log.error(f'Unable to open URL: {url2}')
return False
if r.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {r.status_code}')
return False
else:
try:

36
nzb2media/auto_process/games.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import shutil
@ -11,6 +12,9 @@ from nzb2media.utils.common import flatten
from nzb2media.utils.encoding import convert_to_ascii
from nzb2media.utils.network import server_responding
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -46,7 +50,7 @@ def process(
# Begin processing
url = nzb2media.utils.common.create_url(scheme, host, port, web_root)
if not server_responding(url):
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -66,36 +70,30 @@ def process(
'status': download_status,
}
logger.debug(f'Opening URL: {url}', section)
log.debug(f'Opening URL: {url}')
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 300))
except requests.ConnectionError:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
)
result = r.json()
logger.postprocess(result, section)
log.debug(result)
if library:
logger.postprocess(f'moving files to library: {library}', section)
log.debug(f'moving files to library: {library}')
try:
shutil.move(dir_name, os.path.join(library, input_name))
except Exception:
logger.error(
f'Unable to move {dir_name} to {os.path.join(library, input_name)}',
section,
)
log.error(f'Unable to move {dir_name} to {os.path.join(library, input_name)}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to move files',
)
else:
logger.error(
'No library specified to move files to. Please edit your configuration.',
section,
)
log.error('No library specified to move files to. Please edit your configuration.')
return ProcessResult.failure(
f'{section}: Failed to post-process - No library defined in '
f'{section}',
@ -106,24 +104,18 @@ def process(
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {r.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status '
f'{r.status_code}',
)
elif result['success']:
logger.postprocess(
f'SUCCESS: Status for {gamez_id} has been set to {download_status} in Gamez',
section,
)
log.debug(f'SUCCESS: Status for {gamez_id} has been set to {download_status} in Gamez')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
else:
logger.error(
f'FAILED: Status for {gamez_id} has NOT been updated in Gamez',
section,
)
log.error(f'FAILED: Status for {gamez_id} has NOT been updated in Gamez')
return ProcessResult.failure(
f'{section}: Failed to post-process - Returned log from {section} '
f'was not as expected.',

302
nzb2media/auto_process/movies.py
View file

@ -1,6 +1,7 @@
from __future__ import annotations
import json
import logging
import os
import time
@ -24,6 +25,9 @@ from nzb2media.utils.nzb import report_nzb
from nzb2media.utils.paths import remote_dir
from nzb2media.utils.paths import remove_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -86,9 +90,7 @@ def process(
route = web_root
base_url = nzb2media.utils.common.create_url(scheme, host, port, route)
if not apikey:
logger.info(
'No CouchPotato or Radarr apikey entered. Performing transcoder functions only',
)
log.info('No CouchPotato or Radarr apikey entered. Performing transcoder functions only')
release = None
elif server_responding(base_url):
if section == 'CouchPotato':
@ -96,7 +98,7 @@ def process(
else:
release = None
else:
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -140,9 +142,7 @@ def process(
)
and extract
):
logger.debug(
f'Checking for archives to extract in directory: {dir_name}',
)
log.debug(f'Checking for archives to extract in directory: {dir_name}')
nzb2media.extract_files(dir_name)
input_name, dir_name = convert_to_ascii(input_name, dir_name)
@ -164,16 +164,10 @@ def process(
rename_subs(dir_name)
if num_files and valid_files == num_files:
if status:
logger.info(
f'Status shown as failed from Downloader, but {good_files} valid video files found. Setting as success.',
section,
)
log.info(f'Status shown as failed from Downloader, but {good_files} valid video files found. Setting as success.')
status = 0
elif num_files and valid_files < num_files:
logger.info(
'Status shown as success from Downloader, but corrupt video files found. Setting as failed.',
section,
)
log.info('Status shown as success from Downloader, but corrupt video files found. Setting as failed.')
status = 1
if (
'NZBOP_VERSION' in os.environ
@ -181,33 +175,21 @@ def process(
):
print('[NZB] MARK=BAD')
if good_files == num_files:
logger.debug(
f'Video marked as failed due to missing required language: {nzb2media.REQUIRE_LAN}',
section,
)
log.debug(f'Video marked as failed due to missing required language: {nzb2media.REQUIRE_LAN}')
else:
logger.debug(
'Video marked as failed due to missing playable audio or video',
section,
)
log.debug('Video marked as failed due to missing playable audio or video')
if (
good_files < num_files and failure_link
): # only report corrupt files
failure_link += '&corrupt=true'
elif client_agent == 'manual':
logger.warning(
f'No media files found in directory {dir_name} to manually process.',
section,
)
log.warning(f'No media files found in directory {dir_name} to manually process.')
return ProcessResult(
message='',
status_code=0, # Success (as far as this script is concerned)
)
else:
logger.warning(
f'No media files found in directory {dir_name}. Processing this as a failed download',
section,
)
log.warning(f'No media files found in directory {dir_name}. Processing this as a failed download')
status = 1
if (
'NZBOP_VERSION' in os.environ
@ -219,25 +201,15 @@ def process(
if nzb2media.TRANSCODE == 1:
result, new_dir_name = transcoder.transcode_directory(dir_name)
if result == 0:
logger.debug(
f'Transcoding succeeded for files in {dir_name}', section,
)
log.debug(f'Transcoding succeeded for files in {dir_name}')
dir_name = new_dir_name
logger.debug(
f'Config setting \'chmodDirectory\' currently set to {oct(chmod_directory)}',
section,
)
log.debug(f'Config setting \'chmodDirectory\' currently set to {oct(chmod_directory)}')
if chmod_directory:
logger.info(
f'Attempting to set the octal permission of \'{oct(chmod_directory)}\' on directory \'{dir_name}\'',
section,
)
log.info(f'Attempting to set the octal permission of \'{oct(chmod_directory)}\' on directory \'{dir_name}\'')
nzb2media.rchmod(dir_name, chmod_directory)
else:
logger.error(
f'Transcoding failed for files in {dir_name}', section,
)
log.error(f'Transcoding failed for files in {dir_name}')
return ProcessResult(
message=f'{section}: Failed to post-process - Transcoding failed',
status_code=1,
@ -252,13 +224,11 @@ def process(
client_agent in [nzb2media.TORRENT_CLIENT_AGENT, 'manual']
and nzb2media.USE_LINK == 'move-sym'
):
logger.debug(f'Renaming: {video} to: {video2}')
log.debug(f'Renaming: {video} to: {video2}')
os.rename(video, video2)
if not apikey: # If only using Transcoder functions, exit here.
logger.info(
'No CouchPotato or Radarr or Watcher3 apikey entered. Processing completed.',
)
log.info('No CouchPotato or Radarr or Watcher3 apikey entered. Processing completed.')
return ProcessResult(
message=f'{section}: Successfully post-processed {input_name}',
status_code=0,
@ -280,10 +250,8 @@ def process(
command = 'renamer.scan'
url = f'{base_url}{command}'
logger.debug(f'Opening URL: {url} with PARAMS: {params}', section)
logger.postprocess(
f'Starting {method} scan for {input_name}', section,
)
log.debug(f'Opening URL: {url} with PARAMS: {params}')
log.debug(f'Starting {method} scan for {input_name}')
if section == 'Radarr':
payload = {
@ -294,12 +262,8 @@ def process(
}
if not download_id:
payload.pop('downloadClientId')
logger.debug(
f'Opening URL: {base_url} with PARAMS: {payload}', section,
)
logger.postprocess(
f'Starting DownloadedMoviesScan scan for {input_name}', section,
)
log.debug(f'Opening URL: {base_url} with PARAMS: {payload}')
log.debug(f'Starting DownloadedMoviesScan scan for {input_name}')
if section == 'Watcher3':
if input_name and os.path.isfile(
@ -316,24 +280,20 @@ def process(
}
if not download_id:
payload.pop('guid')
logger.debug(
f'Opening URL: {base_url} with PARAMS: {payload}', section,
)
logger.postprocess(
f'Starting postprocessing scan for {input_name}', section,
)
log.debug(f'Opening URL: {base_url} with PARAMS: {payload}')
log.debug(f'Starting postprocessing scan for {input_name}')
try:
if section == 'CouchPotato':
r = requests.get(
response = requests.get(
url, params=params, verify=False, timeout=(30, 1800),
)
elif section == 'Watcher3':
r = requests.post(
response = requests.post(
base_url, data=payload, verify=False, timeout=(30, 1800),
)
else:
r = requests.post(
response = requests.post(
base_url,
data=json.dumps(payload),
headers=headers,
@ -342,30 +302,25 @@ def process(
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error('Unable to open URL', section)
log.error('Unable to open URL')
return ProcessResult(
message='{0}: Failed to post-process - Unable to connect to {0}'.format(
section,
),
message=f'{section}: Failed to post-process - Unable to connect to {section}',
status_code=1,
)
result = r.json()
if r.status_code not in [
result = response.json()
if response.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {response.status_code}')
return ProcessResult(
message=f'{section}: Failed to post-process - Server returned status {r.status_code}',
message=f'{section}: Failed to post-process - Server returned status {response.status_code}',
status_code=1,
)
elif section == 'CouchPotato' and result['success']:
logger.postprocess(
f'SUCCESS: Finished {method} scan for folder {dir_name}',
section,
)
log.debug(f'SUCCESS: Finished {method} scan for folder {dir_name}')
if method == 'manage':
return ProcessResult(
message=f'{section}: Successfully post-processed {input_name}',
@ -374,13 +329,13 @@ def process(
elif section == 'Radarr':
try:
scan_id = int(result['id'])
logger.debug(f'Scan started with id: {scan_id}', section)
except Exception as e:
logger.warning(f'No scan id was returned due to: {e}', section)
log.debug(f'Scan started with id: {scan_id}')
except Exception as error:
log.warning(f'No scan id was returned due to: {error}')
scan_id = None
elif section == 'Watcher3' and result['status'] == 'finished':
update_movie_status = result['tasks']['update_movie_status']
logger.postprocess(f'Watcher3 updated status to {section}')
log.debug(f'Watcher3 updated status to {section}')
if update_movie_status == 'Finished':
return ProcessResult(
message=f'{section}: Successfully post-processed {input_name}',
@ -392,38 +347,26 @@ def process(
status_code=1,
)
else:
logger.error(
f'FAILED: {method} scan was unable to finish for folder {dir_name}. exiting!',
section,
)
log.error(f'FAILED: {method} scan was unable to finish for folder {dir_name}. exiting!')
return ProcessResult(
message=f'{section}: Failed to post-process - Server did not return success',
status_code=1,
)
else:
nzb2media.FAILED = True
logger.postprocess(
f'FAILED DOWNLOAD DETECTED FOR {input_name}', section,
)
log.debug(f'FAILED DOWNLOAD DETECTED FOR {input_name}')
if failure_link:
report_nzb(failure_link, client_agent)
if section == 'Radarr':
logger.postprocess(
f'SUCCESS: Sending failed download to {section} for CDH processing',
section,
)
log.debug(f'SUCCESS: Sending failed download to {section} for CDH processing')
return ProcessResult(
message='{0}: Sending failed download back to {0}'.format(
section,
),
status_code=1, # Return as failed to flag this in the downloader.
message=f'{section}: Sending failed download back to {section}',
status_code=1,
# Return as failed to flag this in the downloader.
) # Return failed flag, but log the event as successful.
elif section == 'Watcher3':
logger.postprocess(
f'Sending failed download to {section} for CDH processing',
section,
)
log.debug(f'Sending failed download to {section} for CDH processing')
path = remote_dir(dir_name) if remote_path else dir_name
if input_name and os.path.isfile(
os.path.join(dir_name, input_name),
@ -435,17 +378,16 @@ def process(
'guid': download_id,
'mode': 'failed',
}
r = requests.post(
response = requests.post(
base_url, data=payload, verify=False, timeout=(30, 1800),
)
result = r.json()
logger.postprocess(f'Watcher3 response: {result}')
result = response.json()
log.debug(f'Watcher3 response: {result}')
if result['status'] == 'finished':
return ProcessResult(
message='{0}: Sending failed download back to {0}'.format(
section,
),
status_code=1, # Return as failed to flag this in the downloader.
message=f'{section}: Sending failed download back to {section}',
status_code=1,
# Return as failed to flag this in the downloader.
) # Return failed flag, but log the event as successful.
if (
@ -453,117 +395,93 @@ def process(
and os.path.isdir(dir_name)
and not os.path.dirname(dir_name) == dir_name
):
logger.postprocess(
f'Deleting failed files and folder {dir_name}', section,
)
log.debug(f'Deleting failed files and folder {dir_name}')
remove_dir(dir_name)
if not release_id and not media_id:
logger.error(
f'Could not find a downloaded movie in the database matching {input_name}, exiting!',
section,
)
log.error(f'Could not find a downloaded movie in the database matching {input_name}, exiting!')
return ProcessResult(
message='{0}: Failed to post-process - Failed download not found in {0}'.format(
section,
),
message='{0}: Failed to post-process - Failed download not found in {0}'.format(section),
status_code=1,
)
if release_id:
logger.postprocess(
f'Setting failed release {input_name} to ignored ...', section,
)
log.debug(f'Setting failed release {input_name} to ignored ...')
url = f'{base_url}release.ignore'
params = {'id': release_id}
logger.debug(f'Opening URL: {url} with PARAMS: {params}', section)
log.debug(f'Opening URL: {url} with PARAMS: {params}')
try:
r = requests.get(
url, params=params, verify=False, timeout=(30, 120),
response = requests.get(
url, params=params, verify=False,
timeout=(30, 120),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL {url}', section)
log.error(f'Unable to open URL {url}')
return ProcessResult(
message='{0}: Failed to post-process - Unable to connect to {0}'.format(
section,
),
message='{0}: Failed to post-process - Unable to connect to {0}'.format(section),
status_code=1,
)
result = r.json()
if r.status_code not in [
result = response.json()
if response.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(
f'Server returned status {r.status_code}', section,
)
log.error(f'Server returned status {response.status_code}')
return ProcessResult(
status_code=1,
message=f'{section}: Failed to post-process - Server returned status {r.status_code}',
message=f'{section}: Failed to post-process - Server returned status {response.status_code}',
)
elif result['success']:
logger.postprocess(
f'SUCCESS: {input_name} has been set to ignored ...',
section,
)
log.debug(f'SUCCESS: {input_name} has been set to ignored ...')
else:
logger.warning(
f'FAILED: Unable to set {input_name} to ignored!', section,
)
log.warning(f'FAILED: Unable to set {input_name} to ignored!')
return ProcessResult(
message=f'{section}: Failed to post-process - Unable to set {input_name} to ignored',
status_code=1,
)
logger.postprocess(
'Trying to snatch the next highest ranked release.', section,
)
log.debug('Trying to snatch the next highest ranked release.')
url = f'{base_url}movie.searcher.try_next'
logger.debug(f'Opening URL: {url}', section)
log.debug(f'Opening URL: {url}')
try:
r = requests.get(
response = requests.get(
url,
params={'media_id': media_id},
verify=False,
timeout=(30, 600),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL {url}', section)
log.error(f'Unable to open URL {url}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
)
result = r.json()
if r.status_code not in [
result = response.json()
if response.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {response.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status '
f'{r.status_code}',
f'{response.status_code}',
)
elif result['success']:
logger.postprocess(
'SUCCESS: Snatched the next highest release ...', section,
)
log.debug('SUCCESS: Snatched the next highest release ...')
return ProcessResult.success(
f'{section}: Successfully snatched next highest release',
)
else:
logger.postprocess(
'SUCCESS: Unable to find a new release to snatch now. CP will keep searching!',
section,
)
log.debug('SUCCESS: Unable to find a new release to snatch now. CP will keep searching!')
return ProcessResult.success(
f'{section}: No new release found now. '
f'{section} will keep searching',
@ -584,9 +502,7 @@ def process(
# we will now check to see if CPS has finished renaming before returning to TorrentToMedia and unpausing.
timeout = time.time() + 60 * wait_for
while time.time() < timeout: # only wait 2 (default) minutes, then return.
logger.postprocess(
'Checking for status change, please stand by ...', section,
)
log.debug('Checking for status change, please stand by ...')
if section == 'CouchPotato':
release = get_release(base_url, imdbid, download_id, release_id)
scan_id = None
@ -600,19 +516,13 @@ def process(
release_status_old is None
): # we didn't have a release before, but now we do.
title = release[release_id]['title']
logger.postprocess(
f'SUCCESS: Movie {title} has now been added to CouchPotato with release status of [{str(release_status_new).upper()}]',
section,
)
log.debug(f'SUCCESS: Movie {title} has now been added to CouchPotato with release status of [{str(release_status_new).upper()}]')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
if release_status_new != release_status_old:
logger.postprocess(
f'SUCCESS: Release {release_id} has now been marked with a status of [{str(release_status_new).upper()}]',
section,
)
log.debug(f'SUCCESS: Release {release_id} has now been marked with a status of [{str(release_status_new).upper()}]')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
@ -622,33 +532,21 @@ def process(
url = f'{base_url}/{scan_id}'
command_status = command_complete(url, params, headers, section)
if command_status:
logger.debug(
f'The Scan command return status: {command_status}',
section,
)
log.debug(f'The Scan command return status: {command_status}')
if command_status in ['completed']:
logger.debug(
'The Scan command has completed successfully. Renaming was successful.',
section,
)
log.debug('The Scan command has completed successfully. Renaming was successful.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
elif command_status in ['failed']:
logger.debug(
'The Scan command has failed. Renaming was not successful.',
section,
)
log.debug('The Scan command has failed. Renaming was not successful.')
# return ProcessResult(
# message='{0}: Failed to post-process {1}'.format(section, input_name),
# status_code=1,
# )
if not os.path.isdir(dir_name):
logger.postprocess(
f'SUCCESS: Input Directory [{dir_name}] has been processed and removed',
section,
)
log.debug(f'SUCCESS: Input Directory [{dir_name}] has been processed and removed')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
@ -656,10 +554,7 @@ def process(
elif not list_media_files(
dir_name, media=True, audio=False, meta=False, archives=True,
):
logger.postprocess(
f'SUCCESS: Input Directory [{dir_name}] has no remaining media files. This has been fully processed.',
section,
)
log.debug(f'SUCCESS: Input Directory [{dir_name}] has no remaining media files. This has been fully processed.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
@ -671,19 +566,12 @@ def process(
if section == 'Radarr' and completed_download_handling(
url2, headers, section=section,
):
logger.debug(
f'The Scan command did not return status completed, but complete Download Handling is enabled. Passing back to {section}.',
section,
)
log.debug(f'The Scan command did not return status completed, but complete Download Handling is enabled. Passing back to {section}.')
return ProcessResult.success(
f'{section}: Complete DownLoad Handling is enabled. Passing back '
f'to {section}',
)
logger.warning(
f'{input_name} does not appear to have changed status after {wait_for} minutes, Please check your logs.',
section,
)
log.warning(f'{input_name} does not appear to have changed status after {wait_for} minutes, Please check your logs.')
return ProcessResult.failure(
f'{section}: Failed to post-process - No change in status',
)
@ -702,33 +590,33 @@ def get_release(base_url, imdb_id=None, download_id=None, release_id=None):
params['id'] = release_id or imdb_id
if not (release_id or imdb_id or download_id):
logger.debug('No information available to filter CP results')
log.debug('No information available to filter CP results')
return results
url = f'{base_url}{cmd}'
logger.debug(f'Opening URL: {url} with PARAMS: {params}')
log.debug(f'Opening URL: {url} with PARAMS: {params}')
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 60))
except requests.ConnectionError:
logger.error(f'Unable to open URL {url}')
log.error(f'Unable to open URL {url}')
return results
try:
result = r.json()
except ValueError:
# ValueError catches simplejson's JSONDecodeError and json's ValueError
logger.error('CouchPotato returned the following non-json data')
log.error('CouchPotato returned the following non-json data')
for line in r.iter_lines():
logger.error(line)
log.error(line)
return results
if not result['success']:
if 'error' in result:
logger.error(result['error'])
log.error(result['error'])
else:
id_param = params['id']
logger.error(f'no media found for id {id_param}')
log.error(f'no media found for id {id_param}')
return results
# Gather release info and return it back, no need to narrow results

105
nzb2media/auto_process/music.py
View file

@ -1,6 +1,7 @@
from __future__ import annotations
import json
import logging
import os
import time
@ -17,6 +18,9 @@ from nzb2media.utils.network import server_responding
from nzb2media.utils.paths import remote_dir
from nzb2media.utils.paths import remove_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -59,7 +63,7 @@ def process(
route = f'{web_root}/api/v1' if section == 'Lidarr' else f'{web_root}/api'
url = nzb2media.utils.common.create_url(scheme, host, port, route)
if not server_responding(url):
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -88,9 +92,7 @@ def process(
)
and extract
):
logger.debug(
f'Checking for archives to extract in directory: {dir_name}',
)
log.debug(f'Checking for archives to extract in directory: {dir_name}')
nzb2media.extract_files(dir_name)
input_name, dir_name = convert_to_ascii(input_name, dir_name)
@ -127,10 +129,7 @@ def process(
return res
# The status hasn't changed. uTorrent can resume seeding now.
logger.warning(
f'The music album does not appear to have changed status after {wait_for} minutes. Please check your Logs',
section,
)
log.warning(f'The music album does not appear to have changed status after {wait_for} minutes. Please check your Logs')
return ProcessResult.failure(
f'{section}: Failed to post-process - No change in wanted status',
)
@ -140,13 +139,13 @@ def process(
url = nzb2media.utils.common.create_url(scheme, host, port, route)
headers = {'X-Api-Key': apikey}
if remote_path:
logger.debug(f'remote_path: {remote_dir(dir_name)}', section)
log.debug(f'remote_path: {remote_dir(dir_name)}')
data = {'name': 'Rename', 'path': remote_dir(dir_name)}
else:
logger.debug(f'path: {dir_name}', section)
log.debug(f'path: {dir_name}')
data = {'name': 'Rename', 'path': dir_name}
try:
logger.debug(f'Opening URL: {url} with data: {data}', section)
log.debug(f'Opening URL: {url} with data: {data}')
r = requests.post(
url,
data=json.dumps(data),
@ -156,7 +155,7 @@ def process(
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL: {url}', section)
log.error(f'Unable to open URL: {url}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
@ -165,9 +164,9 @@ def process(
try:
res = r.json()
scan_id = int(res['id'])
logger.debug(f'Scan started with id: {scan_id}', section)
except Exception as e:
logger.warning(f'No scan id was returned due to: {e}', section)
log.debug(f'Scan started with id: {scan_id}')
except Exception as error:
log.warning(f'No scan id was returned due to: {error}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to start scan',
)
@ -182,38 +181,24 @@ def process(
break
n += 1
if command_status:
logger.debug(
f'The Scan command return status: {command_status}', section,
)
log.debug(f'The Scan command return status: {command_status}')
if not os.path.exists(dir_name):
logger.debug(
f'The directory {dir_name} has been removed. Renaming was successful.',
section,
)
log.debug(f'The directory {dir_name} has been removed. Renaming was successful.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
elif command_status and command_status in ['completed']:
logger.debug(
'The Scan command has completed successfully. Renaming was successful.',
section,
)
log.debug('The Scan command has completed successfully. Renaming was successful.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
elif command_status and command_status in ['failed']:
logger.debug(
'The Scan command has failed. Renaming was not successful.',
section,
)
log.debug('The Scan command has failed. Renaming was not successful.')
# return ProcessResult.failure(
# f'{section}: Failed to post-process {input_name}'
# )
else:
logger.debug(
f'The Scan command did not return status completed. Passing back to {section} to attempt complete download handling.',
section,
)
log.debug(f'The Scan command did not return status completed. Passing back to {section} to attempt complete download handling.')
return ProcessResult(
message=f'{section}: Passing back to {section} to attempt '
f'Complete Download Handling',
@ -222,24 +207,19 @@ def process(
else:
if section == 'Lidarr':
logger.postprocess(
f'FAILED: The download failed. Sending failed download to {section} for CDH processing',
section,
)
log.debug(f'FAILED: The download failed. Sending failed download to {section} for CDH processing')
# Return as failed to flag this in the downloader.
return ProcessResult.failure(
f'{section}: Download Failed. Sending back to {section}',
)
else:
logger.warning('FAILED DOWNLOAD DETECTED', section)
log.warning('FAILED DOWNLOAD DETECTED')
if (
delete_failed
and os.path.isdir(dir_name)
and not os.path.dirname(dir_name) == dir_name
):
logger.postprocess(
f'Deleting failed files and folder {dir_name}', section,
)
log.postprocess(f'Deleting failed files and folder {dir_name}')
remove_dir(dir_name)
# Return as failed to flag this in the downloader.
return ProcessResult.failure(
@ -251,21 +231,19 @@ def process(
def get_status(url, apikey, dir_name):
logger.debug(
f'Attempting to get current status for release:{os.path.basename(dir_name)}',
)
log.debug(f'Attempting to get current status for release:{os.path.basename(dir_name)}')
params = {
'apikey': apikey,
'cmd': 'getHistory',
}
logger.debug(f'Opening URL: {url} with PARAMS: {params}')
log.debug(f'Opening URL: {url} with PARAMS: {params}')
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 120))
except requests.RequestException:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return None
try:
@ -284,43 +262,34 @@ def force_process(
):
release_status = get_status(url, apikey, dir_name)
if not release_status:
logger.error(
f'Could not find a status for {input_name}, is it in the wanted list ?',
section,
)
log.error(f'Could not find a status for {input_name}, is it in the wanted list ?')
logger.debug(f'Opening URL: {url} with PARAMS: {params}', section)
log.debug(f'Opening URL: {url} with PARAMS: {params}')
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 300))
except requests.ConnectionError:
logger.error(f'Unable to open URL {url}', section)
log.error(f'Unable to open URL {url}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
)
logger.debug(f'Result: {r.text}', section)
log.debug(f'Result: {r.text}')
if r.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {r.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status {r.status_code}',
)
elif r.text == 'OK':
logger.postprocess(
f'SUCCESS: Post-Processing started for {input_name} in folder {dir_name} ...',
section,
)
log.debug(f'SUCCESS: Post-Processing started for {input_name} in folder {dir_name} ...')
else:
logger.error(
f'FAILED: Post-Processing has NOT started for {input_name} in folder {dir_name}. exiting!',
section,
)
log.error(f'FAILED: Post-Processing has NOT started for {input_name} in folder {dir_name}. exiting!')
return ProcessResult.failure(
f'{section}: Failed to post-process - Returned log from {section} '
f'was not as expected.',
@ -333,18 +302,12 @@ def force_process(
if (
current_status is not None and current_status != release_status
): # Something has changed. CPS must have processed this movie.
logger.postprocess(
f'SUCCESS: This release is now marked as status [{current_status}]',
section,
)
log.debug(f'SUCCESS: This release is now marked as status [{current_status}]')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
if not os.path.isdir(dir_name):
logger.postprocess(
f'SUCCESS: The input directory {dir_name} has been removed Processing must have finished.',
section,
)
log.debug(f'SUCCESS: The input directory {dir_name} has been removed Processing must have finished.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)

175
nzb2media/auto_process/tv.py
View file

@ -3,6 +3,7 @@ from __future__ import annotations
import copy
import errno
import json
import logging
import os
import time
@ -27,6 +28,9 @@ from nzb2media.utils.nzb import report_nzb
from nzb2media.utils.paths import remote_dir
from nzb2media.utils.paths import remove_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
*,
@ -90,12 +94,10 @@ def process(
# Should be changed after refactor.
fork, fork_params = init_sickbeard.auto_fork()
elif not username and not apikey and not sso_username:
logger.info(
'No SickBeard / SiCKRAGE username or Sonarr apikey entered. Performing transcoder functions only',
)
log.info('No SickBeard / SiCKRAGE username or Sonarr apikey entered. Performing transcoder functions only')
fork, fork_params = 'None', {}
else:
logger.error('Server did not respond. Exiting', section)
log.error('Server did not respond. Exiting')
return ProcessResult.failure(
f'{section}: Failed to post-process - {section} did not respond.',
)
@ -123,9 +125,9 @@ def process(
if dir_name:
try:
os.makedirs(dir_name) # Attempt to create the directory
except OSError as e:
except OSError as error:
# Re-raise the error if it wasn't about the directory not existing
if e.errno != errno.EEXIST:
if error.errno != errno.EEXIST:
raise
if 'process_method' not in fork_params or (
@ -150,9 +152,7 @@ def process(
)
and extract
):
logger.debug(
f'Checking for archives to extract in directory: {dir_name}',
)
log.debug(f'Checking for archives to extract in directory: {dir_name}')
nzb2media.extract_files(dir_name)
input_name, dir_name = convert_to_ascii(input_name, dir_name)
@ -179,10 +179,10 @@ def process(
rename_subs(dir_name)
if num_files > 0:
if valid_files == num_files and not status == 0:
logger.info('Found Valid Videos. Setting status Success')
log.info('Found Valid Videos. Setting status Success')
status = 0
if valid_files < num_files and status == 0:
logger.info('Found corrupt videos. Setting status Failed')
log.info('Found corrupt videos. Setting status Failed')
status = 1
if (
'NZBOP_VERSION' in os.environ
@ -190,42 +190,26 @@ def process(
):
print('[NZB] MARK=BAD')
if good_files == num_files:
logger.debug(
f'Video marked as failed due to missing required language: {nzb2media.REQUIRE_LAN}',
section,
)
log.debug(f'Video marked as failed due to missing required language: {nzb2media.REQUIRE_LAN}')
else:
logger.debug(
'Video marked as failed due to missing playable audio or video',
section,
)
log.debug('Video marked as failed due to missing playable audio or video')
if (
good_files < num_files and failure_link
): # only report corrupt files
failure_link += '&corrupt=true'
elif client_agent == 'manual':
logger.warning(
f'No media files found in directory {dir_name} to manually process.',
section,
)
log.warning(f'No media files found in directory {dir_name} to manually process.')
# Success (as far as this script is concerned)
return ProcessResult.success()
elif nzb_extraction_by == 'Destination':
logger.info(
'Check for media files ignored because nzbExtractionBy is set to Destination.',
)
log.info('Check for media files ignored because nzbExtractionBy is set to Destination.')
if status == 0:
logger.info('Setting Status Success.')
log.info('Setting Status Success.')
else:
logger.info(
'Downloader reported an error during download or verification. Processing this as a failed download.',
)
log.info('Downloader reported an error during download or verification. Processing this as a failed download.')
status = 1
else:
logger.warning(
f'No media files found in directory {dir_name}. Processing this as a failed download',
section,
)
log.warning(f'No media files found in directory {dir_name}. Processing this as a failed download')
status = 1
if (
'NZBOP_VERSION' in os.environ
@ -238,26 +222,15 @@ def process(
): # only transcode successful downloads
result, new_dir_name = transcoder.transcode_directory(dir_name)
if result == 0:
logger.debug(
f'SUCCESS: Transcoding succeeded for files in {dir_name}',
section,
)
log.debug(f'SUCCESS: Transcoding succeeded for files in {dir_name}')
dir_name = new_dir_name
logger.debug(
f'Config setting \'chmodDirectory\' currently set to {oct(chmod_directory)}',
section,
)
log.debug(f'Config setting \'chmodDirectory\' currently set to {oct(chmod_directory)}')
if chmod_directory:
logger.info(
f'Attempting to set the octal permission of \'{oct(chmod_directory)}\' on directory \'{dir_name}\'',
section,
)
log.info(f'Attempting to set the octal permission of \'{oct(chmod_directory)}\' on directory \'{dir_name}\'')
nzb2media.rchmod(dir_name, chmod_directory)
else:
logger.error(
f'FAILED: Transcoding failed for files in {dir_name}', section,
)
log.error(f'FAILED: Transcoding failed for files in {dir_name}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Transcoding failed',
)
@ -343,45 +316,31 @@ def process(
if status == 0:
if section == 'NzbDrone' and not apikey:
logger.info('No Sonarr apikey entered. Processing completed.')
log.info('No Sonarr apikey entered. Processing completed.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
logger.postprocess(
'SUCCESS: The download succeeded, sending a post-process request',
section,
)
log.debug('SUCCESS: The download succeeded, sending a post-process request')
else:
nzb2media.FAILED = True
if failure_link:
report_nzb(failure_link, client_agent)
if 'failed' in fork_params:
logger.postprocess(
f'FAILED: The download failed. Sending \'failed\' process request to {fork} branch',
section,
)
log.debug(f'FAILED: The download failed. Sending \'failed\' process request to {fork} branch')
elif section == 'NzbDrone':
logger.postprocess(
f'FAILED: The download failed. Sending failed download to {fork} for CDH processing',
section,
)
log.debug(f'FAILED: The download failed. Sending failed download to {fork} for CDH processing')
# Return as failed to flag this in the downloader.
return ProcessResult.failure(
f'{section}: Download Failed. Sending back to {section}',
)
else:
logger.postprocess(
f'FAILED: The download failed. {fork} branch does not handle failed downloads. Nothing to process',
section,
)
log.debug(f'FAILED: The download failed. {fork} branch does not handle failed downloads. Nothing to process')
if (
delete_failed
and os.path.isdir(dir_name)
and not os.path.dirname(dir_name) == dir_name
):
logger.postprocess(
f'Deleting failed files and folder {dir_name}', section,
)
log.debug(f'Deleting failed files and folder {dir_name}')
remove_dir(dir_name)
# Return as failed to flag this in the downloader.
return ProcessResult.failure(
@ -410,7 +369,7 @@ def process(
headers = {'X-Api-Key': apikey}
# params = {'sortKey': 'series.title', 'page': 1, 'pageSize': 1, 'sortDir': 'asc'}
if remote_path:
logger.debug(f'remote_path: {remote_dir(dir_name)}', section)
log.debug(f'remote_path: {remote_dir(dir_name)}')
data = {
'name': 'DownloadedEpisodesScan',
'path': remote_dir(dir_name),
@ -418,7 +377,7 @@ def process(
'importMode': import_mode,
}
else:
logger.debug(f'path: {dir_name}', section)
log.debug(f'path: {dir_name}')
data = {
'name': 'DownloadedEpisodesScan',
'path': dir_name,
@ -435,15 +394,14 @@ def process(
else:
s = requests.Session()
logger.debug(
f'Opening URL: {url} with params: {fork_params}', section,
log.debug(f'Opening URL: {url} with params: {fork_params}', section,
)
if not apikey and username and password:
login = f'{web_root}/login'
login_params = {'username': username, 'password': password}
r = s.get(login, verify=False, timeout=(30, 60))
if r.status_code in [401, 403] and r.cookies.get('_xsrf'):
login_params['_xsrf'] = r.cookies.get('_xsrf')
response = s.get(login, verify=False, timeout=(30, 60))
if response.status_code in [401, 403] and response.cookies.get('_xsrf'):
login_params['_xsrf'] = response.cookies.get('_xsrf')
s.post(
login,
data=login_params,
@ -451,7 +409,7 @@ def process(
verify=False,
timeout=(30, 60),
)
r = s.get(
response = s.get(
url,
auth=(username, password),
params=fork_params,
@ -495,7 +453,7 @@ def process(
else:
params = fork_params
r = s.get(
response = s.get(
url,
params=params,
stream=True,
@ -503,8 +461,8 @@ def process(
timeout=(30, 1800),
)
elif section == 'NzbDrone':
logger.debug(f'Opening URL: {url} with data: {data}', section)
r = requests.post(
log.debug(f'Opening URL: {url} with data: {data}')
response = requests.post(
url,
data=json.dumps(data),
headers=headers,
@ -513,21 +471,21 @@ def process(
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL: {url}', section)
log.error(f'Unable to open URL: {url}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Unable to connect to '
f'{section}',
)
if r.status_code not in [
if response.status_code not in [
requests.codes.ok,
requests.codes.created,
requests.codes.accepted,
]:
logger.error(f'Server returned status {r.status_code}', section)
log.error(f'Server returned status {response.status_code}')
return ProcessResult.failure(
f'{section}: Failed to post-process - Server returned status '
f'{r.status_code}',
f'{response.status_code}',
)
success = False
@ -535,13 +493,13 @@ def process(
started = False
if section == 'SickBeard':
if apikey:
if r.json()['result'] == 'success':
if response.json()['result'] == 'success':
success = True
else:
for line in r.iter_lines():
for line in response.iter_lines():
if line:
line = line.decode('utf-8')
logger.postprocess(line, section)
log.debug(line)
if 'Moving file from' in line:
input_name = os.path.split(line)[1]
if 'added to the queue' in line:
@ -558,16 +516,16 @@ def process(
if api_version >= 2:
success = True
else:
if r.json()['result'] == 'success':
if response.json()['result'] == 'success':
success = True
elif section == 'NzbDrone':
try:
res = r.json()
res = response.json()
scan_id = int(res['id'])
logger.debug(f'Scan started with id: {scan_id}', section)
log.debug(f'Scan started with id: {scan_id}')
started = True
except Exception as e:
logger.warning(f'No scan id was returned due to: {e}', section)
except Exception as error:
log.warning(f'No scan id was returned due to: {error}')
scan_id = None
started = False
@ -576,9 +534,7 @@ def process(
and delete_failed
and not os.path.dirname(dir_name) == dir_name
):
logger.postprocess(
f'Deleting failed files and folder {dir_name}', section,
)
log.debug(f'Deleting failed files and folder {dir_name}')
remove_dir(dir_name)
if success:
@ -596,50 +552,33 @@ def process(
break
n += 1
if command_status:
logger.debug(
f'The Scan command return status: {command_status}', section,
)
log.debug(f'The Scan command return status: {command_status}')
if not os.path.exists(dir_name):
logger.debug(
f'The directory {dir_name} has been removed. Renaming was successful.',
section,
)
log.debug(f'The directory {dir_name} has been removed. Renaming was successful.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
elif command_status and command_status in ['completed']:
logger.debug(
'The Scan command has completed successfully. Renaming was successful.',
section,
)
log.debug('The Scan command has completed successfully. Renaming was successful.')
return ProcessResult.success(
f'{section}: Successfully post-processed {input_name}',
)
elif command_status and command_status in ['failed']:
logger.debug(
'The Scan command has failed. Renaming was not successful.',
section,
)
log.debug('The Scan command has failed. Renaming was not successful.')
# return ProcessResult.failure(
# f'{section}: Failed to post-process {input_name}'
# )
url2 = nzb2media.utils.common.create_url(scheme, host, port, route)
if completed_download_handling(url2, headers, section=section):
logger.debug(
f'The Scan command did not return status completed, but complete Download Handling is enabled. Passing back to {section}.',
section,
)
log.debug(f'The Scan command did not return status completed, but complete Download Handling is enabled. Passing back to {section}.')
return ProcessResult(
message=f'{section}: Complete DownLoad Handling is enabled. '
f'Passing back to {section}',
status_code=status,
)
else:
logger.warning(
'The Scan command did not return a valid status. Renaming was not successful.',
section,
)
log.warning('The Scan command did not return a valid status. Renaming was not successful.')
return ProcessResult.failure(
f'{section}: Failed to post-process {input_name}',
)

45
nzb2media/configuration.py
View file

@ -1,6 +1,7 @@
from __future__ import annotations
import copy
import logging
import os
import shutil
from itertools import chain
@ -9,10 +10,14 @@ import configobj
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class Section(configobj.Section):
def isenabled(self):
# checks if subsection enabled, returns true/false if subsection specified otherwise returns true/false in {}
# checks if subsection enabled, returns true/false if subsection
# specified otherwise returns true/false in {}
if not self.sections:
try:
value = list(ConfigObj.find_key(self, 'enabled'))[0]
@ -118,7 +123,7 @@ class ConfigObj(configobj.ConfigObj, Section):
shutil.copyfile(nzb2media.CONFIG_SPEC_FILE, nzb2media.CONFIG_FILE)
CFG_OLD = config(nzb2media.CONFIG_FILE)
except Exception as error:
logger.error(f'Error {error} when copying to .cfg')
log.error(f'Error {error} when copying to .cfg')
try:
# check for autoProcessMedia.cfg.spec and create if it does not exist
@ -126,7 +131,7 @@ class ConfigObj(configobj.ConfigObj, Section):
shutil.copyfile(nzb2media.CONFIG_FILE, nzb2media.CONFIG_SPEC_FILE)
CFG_NEW = config(nzb2media.CONFIG_SPEC_FILE)
except Exception as error:
logger.error(f'Error {error} when copying to .spec')
log.error(f'Error {error} when copying to .spec')
# check for autoProcessMedia.cfg and autoProcessMedia.cfg.spec and if they don't exist return and fail
if CFG_NEW is None or CFG_OLD is None:
@ -313,11 +318,7 @@ class ConfigObj(configobj.ConfigObj, Section):
os.environ['NZBPO_NDCATEGORY']
== os.environ['NZBPO_SBCATEGORY']
):
logger.warning(
'{x} category is set for SickBeard and Sonarr. Please check your config in NZBGet'.format(
x=os.environ['NZBPO_NDCATEGORY'],
),
)
log.warning('{x} category is set for SickBeard and Sonarr. Please check your config in NZBGet'.format(x=os.environ['NZBPO_NDCATEGORY']))
if (
'NZBPO_RACATEGORY' in os.environ
and 'NZBPO_CPSCATEGORY' in os.environ
@ -326,11 +327,7 @@ class ConfigObj(configobj.ConfigObj, Section):
os.environ['NZBPO_RACATEGORY']
== os.environ['NZBPO_CPSCATEGORY']
):
logger.warning(
'{x} category is set for CouchPotato and Radarr. Please check your config in NZBGet'.format(
x=os.environ['NZBPO_RACATEGORY'],
),
)
log.warning('{x} category is set for CouchPotato and Radarr. Please check your config in NZBGet'.format(x=os.environ['NZBPO_RACATEGORY']))
if (
'NZBPO_RACATEGORY' in os.environ
and 'NZBPO_W3CATEGORY' in os.environ
@ -339,11 +336,7 @@ class ConfigObj(configobj.ConfigObj, Section):
os.environ['NZBPO_RACATEGORY']
== os.environ['NZBPO_W3CATEGORY']
):
logger.warning(
'{x} category is set for Watcher3 and Radarr. Please check your config in NZBGet'.format(
x=os.environ['NZBPO_RACATEGORY'],
),
)
log.warning('{x} category is set for Watcher3 and Radarr. Please check your config in NZBGet'.format(x=os.environ['NZBPO_RACATEGORY']))
if (
'NZBPO_W3CATEGORY' in os.environ
and 'NZBPO_CPSCATEGORY' in os.environ
@ -352,11 +345,7 @@ class ConfigObj(configobj.ConfigObj, Section):
os.environ['NZBPO_W3CATEGORY']
== os.environ['NZBPO_CPSCATEGORY']
):
logger.warning(
'{x} category is set for CouchPotato and Watcher3. Please check your config in NZBGet'.format(
x=os.environ['NZBPO_W3CATEGORY'],
),
)
log.warning('{x} category is set for CouchPotato and Watcher3. Please check your config in NZBGet'.format(x=os.environ['NZBPO_W3CATEGORY']))
if (
'NZBPO_LICATEGORY' in os.environ
and 'NZBPO_HPCATEGORY' in os.environ
@ -365,11 +354,7 @@ class ConfigObj(configobj.ConfigObj, Section):
os.environ['NZBPO_LICATEGORY']
== os.environ['NZBPO_HPCATEGORY']
):
logger.warning(
'{x} category is set for HeadPhones and Lidarr. Please check your config in NZBGet'.format(
x=os.environ['NZBPO_LICATEGORY'],
),
)
log.warning('{x} category is set for HeadPhones and Lidarr. Please check your config in NZBGet'.format(x=os.environ['NZBPO_LICATEGORY']))
section = 'Nzb'
key = 'NZBOP_DESTDIR'
if key in os.environ:
@ -1118,14 +1103,14 @@ class ConfigObj(configobj.ConfigObj, Section):
cfg_new[section][os.environ[env_cat_key]]['enabled'] = 1
except Exception as error:
logger.debug(f'Error {error} when applying NZBGet config')
log.debug(f'Error {error} when applying NZBGet config')
try:
# write our new config to autoProcessMedia.cfg
cfg_new.filename = nzb2media.CONFIG_FILE
cfg_new.write()
except Exception as error:
logger.debug(f'Error {error} when writing changes to .cfg')
log.debug(f'Error {error} when writing changes to .cfg')
return cfg_new

25
nzb2media/databases.py
View file

@ -1,20 +1,25 @@
from __future__ import annotations
import logging
import sys
from nzb2media import main_db
from nzb2media.utils.files import backup_versioned_file
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
MIN_DB_VERSION = 1 # oldest db version we support migrating from
MAX_DB_VERSION = 2
def backup_database(version):
logger.info('Backing up database before upgrade')
log.info('Backing up database before upgrade')
if not backup_versioned_file(main_db.db_filename(), version):
logger.log_error_and_exit(
'Database backup failed, abort upgrading database',
)
logging.critical('Database backup failed, abort upgrading database')
sys.exit(1)
else:
logger.info('Proceeding with upgrade')
log.info('Proceeding with upgrade')
# ======================
@ -47,14 +52,12 @@ class InitialSchema(main_db.SchemaUpgrade):
cur_db_version = self.check_db_version()
if cur_db_version < MIN_DB_VERSION:
logger.log_error_and_exit(
f'Your database version ({cur_db_version}) is too old to migrate from what this version of nzbToMedia supports ({MIN_DB_VERSION}).\nPlease remove nzbtomedia.db file to begin fresh.',
)
log.critical(f'Your database version ({cur_db_version}) is too old to migrate from what this version of nzbToMedia supports ({MIN_DB_VERSION}).\nPlease remove nzbtomedia.db file to begin fresh.')
sys.exit(1)
if cur_db_version > MAX_DB_VERSION:
logger.log_error_and_exit(
f'Your database version ({cur_db_version}) has been incremented past what this version of nzbToMedia supports ({MAX_DB_VERSION}).\nIf you have used other forks of nzbToMedia, your database may be unusable due to their modifications.',
)
log.critical(f'Your database version ({cur_db_version}) has been incremented past what this version of nzbToMedia supports ({MAX_DB_VERSION}).\nIf you have used other forks of nzbToMedia, your database may be unusable due to their modifications.')
sys.exit(1)
if cur_db_version < MAX_DB_VERSION: # We need to upgrade.
queries = [
'CREATE TABLE downloads2 (input_directory TEXT, input_name TEXT, input_hash TEXT, input_id TEXT, client_agent TEXT, status INTEGER, last_update NUMERIC, CONSTRAINT pk_downloadID PRIMARY KEY (input_directory, input_name));',

44
nzb2media/extractor/__init__.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import platform
import shutil
@ -11,13 +12,16 @@ from time import sleep
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def extract(file_path, output_destination):
success = 0
# Using Windows
if platform.system() == 'Windows':
if not os.path.exists(nzb2media.SEVENZIP):
nzb2media.logger.error('EXTRACTOR: Could not find 7-zip, Exiting')
log.error('EXTRACTOR: Could not find 7-zip, Exiting')
return False
wscriptlocation = os.path.join(
os.environ['WINDIR'], 'system32', 'wscript.exe',
@ -109,20 +113,14 @@ def extract(file_path, output_destination):
): # we do have '7za'
extract_commands[k] = ['7za', 'x', '-y']
else:
nzb2media.logger.error(
f'EXTRACTOR: {cmd} not found, disabling support for {k}',
)
log.error(f'EXTRACTOR: {cmd} not found, disabling support for {k}')
del extract_commands[k]
devnull.close()
else:
nzb2media.logger.warning(
'EXTRACTOR: Cannot determine which tool to use when called from Transmission',
)
log.warning('EXTRACTOR: Cannot determine which tool to use when called from Transmission')
if not extract_commands:
nzb2media.logger.warning(
'EXTRACTOR: No archive extracting programs found, plugin will be disabled',
)
log.warning('EXTRACTOR: No archive extracting programs found, plugin will be disabled')
ext = os.path.splitext(file_path)
cmd = []
@ -150,7 +148,7 @@ def extract(file_path, output_destination):
if ext[1] in extract_commands:
cmd = extract_commands[ext[1]]
else:
nzb2media.logger.debug(f'EXTRACTOR: Unknown file type: {ext[1]}')
log.debug(f'EXTRACTOR: Unknown file type: {ext[1]}')
return False
# Create outputDestination folder
@ -166,8 +164,8 @@ def extract(file_path, output_destination):
else:
passwords = []
nzb2media.logger.info(f'Extracting {file_path} to {output_destination}')
nzb2media.logger.debug(f'Extracting {cmd} {file_path} {output_destination}')
log.info(f'Extracting {file_path} to {output_destination}')
log.debug(f'Extracting {cmd} {file_path} {output_destination}')
orig_files = []
orig_dirs = []
@ -192,19 +190,17 @@ def extract(file_path, output_destination):
else:
cmd = nzb2media.NICENESS + cmd
cmd2 = cmd
if not 'gunzip' in cmd: # gunzip doesn't support password
if 'gunzip' not in cmd: # gunzip doesn't support password
cmd2.append('-p-') # don't prompt for password.
p = Popen(
cmd2, stdout=devnull, stderr=devnull, startupinfo=info,
) # should extract files fine.
res = p.wait()
if res == 0: # Both Linux and Windows return 0 for successful.
nzb2media.logger.info(
f'EXTRACTOR: Extraction was successful for {file_path} to {output_destination}',
)
log.info(f'EXTRACTOR: Extraction was successful for {file_path} to {output_destination}')
success = 1
elif len(passwords) > 0 and not 'gunzip' in cmd:
nzb2media.logger.info('EXTRACTOR: Attempting to extract with passwords')
log.info('EXTRACTOR: Attempting to extract with passwords')
for password in passwords:
if (
password == ''
@ -219,17 +215,13 @@ def extract(file_path, output_destination):
) # should extract files fine.
res = p.wait()
if (res >= 0 and platform == 'Windows') or res == 0:
nzb2media.logger.info(
f'EXTRACTOR: Extraction was successful for {file_path} to {output_destination} using password: {password}',
)
log.info(f'EXTRACTOR: Extraction was successful for {file_path} to {output_destination} using password: {password}')
success = 1
break
else:
continue
except Exception:
nzb2media.logger.error(
f'EXTRACTOR: Extraction failed for {file_path}. Could not call command {cmd}',
)
log.error(f'EXTRACTOR: Extraction failed for {file_path}. Could not call command {cmd}')
os.chdir(pwd)
return False
@ -256,7 +248,5 @@ def extract(file_path, output_destination):
pass
return True
else:
nzb2media.logger.error(
f'EXTRACTOR: Extraction failed for {file_path}. Result was {res}',
)
log.error(f'EXTRACTOR: Extraction failed for {file_path}. Result was {res}')
return False

75
nzb2media/main_db.py
View file

@ -1,11 +1,15 @@
from __future__ import annotations
import logging
import re
import sqlite3
import time
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def db_filename(filename='nzbtomedia.db', suffix=None):
"""
@ -52,15 +56,12 @@ class DBConnection:
while attempt < 5:
try:
if args is None:
logger.log(f'{self.filename}: {query}', logger.DB)
log.debug(f'{self.filename}: {query}')
cursor = self.connection.cursor()
cursor.execute(query)
sql_result = cursor.fetchone()[0]
else:
logger.log(
f'{self.filename}: {query} with args {args}',
logger.DB,
)
log.debug(f'{self.filename}: {query} with args {args}')
cursor = self.connection.cursor()
cursor.execute(query, args)
sql_result = cursor.fetchone()[0]
@ -72,16 +73,14 @@ class DBConnection:
'unable to open database file' in error.args[0]
or 'database is locked' in error.args[0]
):
logger.log(f'DB error: {error}', logger.WARNING)
log.warning(f'DB error: {error}')
attempt += 1
time.sleep(1)
else:
logger.log(f'DB error: {error}', logger.ERROR)
log.error(f'DB error: {error}')
raise
except sqlite3.DatabaseError as error:
logger.log(
f'Fatal error executing query: {error}', logger.ERROR,
)
log.error(f'Fatal error executing query: {error}')
raise
return sql_result
@ -98,21 +97,16 @@ class DBConnection:
for qu in querylist:
if len(qu) == 1:
if log_transaction:
logger.log(qu[0], logger.DEBUG)
log.debug(qu[0])
sql_result.append(self.connection.execute(qu[0]))
elif len(qu) > 1:
if log_transaction:
logger.log(
f'{qu[0]} with args {qu[1]}', logger.DEBUG,
)
log.debug(f'{qu[0]} with args {qu[1]}')
sql_result.append(
self.connection.execute(qu[0], qu[1]),
)
self.connection.commit()
logger.log(
f'Transaction with {len(querylist)} query\'s executed',
logger.DEBUG,
)
log.debug(f'Transaction with {len(querylist)} query\'s executed')
return sql_result
except sqlite3.OperationalError as error:
sql_result = []
@ -122,18 +116,16 @@ class DBConnection:
'unable to open database file' in error.args[0]
or 'database is locked' in error.args[0]
):
logger.log(f'DB error: {error}', logger.WARNING)
log.warning(f'DB error: {error}')
attempt += 1
time.sleep(1)
else:
logger.log(f'DB error: {error}', logger.ERROR)
log.error(f'DB error: {error}')
raise
except sqlite3.DatabaseError as error:
if self.connection:
self.connection.rollback()
logger.log(
f'Fatal error executing query: {error}', logger.ERROR,
)
log.error(f'Fatal error executing query: {error}')
raise
return sql_result
@ -148,13 +140,10 @@ class DBConnection:
while attempt < 5:
try:
if args is None:
logger.log(f'{self.filename}: {query}', logger.DB)
log.debug(f'{self.filename}: {query}')
sql_result = self.connection.execute(query)
else:
logger.log(
f'{self.filename}: {query} with args {args}',
logger.DB,
)
log.debug(f'{self.filename}: {query} with args {args}')
sql_result = self.connection.execute(query, args)
self.connection.commit()
# get out of the connection attempt loop since we were successful
@ -164,16 +153,14 @@ class DBConnection:
'unable to open database file' in error.args[0]
or 'database is locked' in error.args[0]
):
logger.log(f'DB error: {error}', logger.WARNING)
log.warning(f'DB error: {error}')
attempt += 1
time.sleep(1)
else:
logger.log(f'DB error: {error}', logger.ERROR)
log.error(f'DB error: {error}')
raise
except sqlite3.DatabaseError as error:
logger.log(
f'Fatal error executing query: {error}', logger.ERROR,
)
log.error(f'Fatal error executing query: {error}')
raise
return sql_result
@ -239,7 +226,7 @@ class DBSanityCheck:
def upgrade_database(connection, schema):
logger.log('Checking database structure...', logger.MESSAGE)
log.info('Checking database structure...')
_process_upgrade(connection, schema)
@ -251,15 +238,9 @@ def pretty_name(class_name):
def _process_upgrade(connection, upgrade_class):
instance = upgrade_class(connection)
logger.log(
f'Checking {pretty_name(upgrade_class.__name__)} database upgrade',
logger.DEBUG,
)
log.debug(f'Checking {pretty_name(upgrade_class.__name__)} database upgrade')
if not instance.test():
logger.log(
f'Database upgrade required: {pretty_name(upgrade_class.__name__)}',
logger.MESSAGE,
)
log.info(f'Database upgrade required: {pretty_name(upgrade_class.__name__)}')
try:
instance.execute()
except sqlite3.DatabaseError as error:
@ -267,15 +248,9 @@ def _process_upgrade(connection, upgrade_class):
f'Error in {upgrade_class.__name__}: {error}',
)
raise
logger.log(
f'{upgrade_class.__name__} upgrade completed',
logger.DEBUG,
)
log.debug(f'{upgrade_class.__name__} upgrade completed')
else:
logger.log(
f'{upgrade_class.__name__} upgrade not required',
logger.DEBUG,
)
log.debug(f'{upgrade_class.__name__} upgrade not required')
for upgradeSubClass in upgrade_class.__subclasses__():
_process_upgrade(connection, upgradeSubClass)

37
nzb2media/managers/pymedusa.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import time
import requests
@ -8,6 +9,9 @@ import nzb2media.utils.common
from nzb2media.auto_process.common import ProcessResult
from nzb2media.managers.sickbeard import SickBeard
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class PyMedusa(SickBeard):
"""PyMedusa class."""
@ -38,10 +42,7 @@ class PyMedusaApiV1(SickBeard):
def api_call(self) -> ProcessResult:
self._process_fork_prarams()
logger.debug(
f'Opening URL: {self.url} with params: {self.sb_init.fork_params}',
self.sb_init.section,
)
log.debug(f'Opening URL: {self.url} with params: {self.sb_init.fork_params}')
try:
response = self.session.get(
self.url,
@ -52,10 +53,7 @@ class PyMedusaApiV1(SickBeard):
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error(
f'Unable to open URL: {self.url}',
self.sb_init.section,
)
log.error(f'Unable to open URL: {self.url}')
return ProcessResult.failure(
f'{self.sb_init.section}: Failed to post-process - Unable to '
f'connect to {self.sb_init.section}',
@ -67,10 +65,7 @@ class PyMedusaApiV1(SickBeard):
requests.codes.accepted,
]
if response.status_code not in successful_status_codes:
logger.error(
f'Server returned status {response.status_code}',
self.sb_init.section,
)
log.error(f'Server returned status {response.status_code}')
result = ProcessResult.failure(
f'{self.sb_init.section}: Failed to post-process - Server '
f'returned status {response.status_code}',
@ -98,7 +93,7 @@ class PyMedusaApiV2(SickBeard):
# Check for an apikey
# This is required with using fork = medusa-apiv2
if not sb_init.apikey:
logger.error(
log.error(
'For the section SickBeard `fork = medusa-apiv2` you also '
'need to configure an `apikey`',
)
@ -119,10 +114,7 @@ class PyMedusaApiV2(SickBeard):
try:
response = self.session.get(url, verify=False, timeout=(30, 1800))
except requests.ConnectionError:
logger.error(
'Unable to get postprocess identifier status',
self.sb_init.section,
)
log.error('Unable to get postprocess identifier status')
return False
try:
@ -134,7 +126,7 @@ class PyMedusaApiV2(SickBeard):
def api_call(self) -> ProcessResult:
self._process_fork_prarams()
logger.debug(f'Opening URL: {self.url}', self.sb_init.section)
log.debug(f'Opening URL: {self.url}')
payload = self.sb_init.fork_params
payload['resource'] = self.sb_init.fork_params['nzbName']
del payload['nzbName']
@ -155,10 +147,7 @@ class PyMedusaApiV2(SickBeard):
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error(
'Unable to send postprocess request',
self.sb_init.section,
)
log.error('Unable to send postprocess request')
return ProcessResult.failure(
f'{self.sb_init.section}: Unable to send postprocess request '
f'to PyMedusa',
@ -169,7 +158,7 @@ class PyMedusaApiV2(SickBeard):
try:
jdata = response.json()
except ValueError:
logger.debug('No data returned from provider')
log.debug('No data returned from provider')
return ProcessResult.failure('No data returned from provider')
else:
jdata = {}
@ -196,7 +185,7 @@ class PyMedusaApiV2(SickBeard):
# Log Medusa's PP logs here.
if response.get('output'):
for line in response['output']:
logger.postprocess(line, self.sb_init.section)
log.postprocess(line)
# For now this will most likely always be True.
# In the future we could return an exit state for when the PP in

111
nzb2media/managers/sickbeard.py
View file

@ -1,6 +1,7 @@
from __future__ import annotations
import copy
import logging
import requests
from oauthlib.oauth2 import LegacyApplicationClient
@ -10,6 +11,9 @@ import nzb2media
from nzb2media.auto_process.common import ProcessResult
from nzb2media.utils.paths import remote_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class InitSickBeard:
"""SickBeard init class.
@ -60,7 +64,7 @@ class InitSickBeard:
# config settings
if nzb2media.FORK_SET:
# keep using determined fork for multiple (manual) post-processing
logger.info(
log.info(
f'{self.section}:{self.input_category} fork already set to '
f'{nzb2media.FORK_SET[0]}',
)
@ -87,7 +91,7 @@ class InitSickBeard:
protocol = 'https://' if self.ssl else 'http://'
if self.section == 'NzbDrone':
logger.info(f'Attempting to verify {self.input_category} fork')
log.info(f'Attempting to verify {self.input_category} fork')
url = nzb2media.utils.common.create_url(
scheme=protocol,
host=self.host,
@ -96,20 +100,20 @@ class InitSickBeard:
)
headers = {'X-Api-Key': self.apikey}
try:
r = requests.get(
response = requests.get(
url,
headers=headers,
stream=True,
verify=False,
)
except requests.ConnectionError:
logger.warning(
log.warning(
f'Could not connect to {self.section}:'
f'{self.input_category} to verify fork!',
)
if not r.ok:
logger.warning(
if not response.ok:
log.warning(
f'Connection to {self.section}:{self.input_category} '
f'failed! Check your configuration',
)
@ -117,7 +121,7 @@ class InitSickBeard:
self.fork = ['default', {}]
elif self.section == 'SiCKRAGE':
logger.info(f'Attempting to verify {self.input_category} fork')
log.info(f'Attempting to verify {self.input_category} fork')
if self.api_version >= 2:
url = nzb2media.utils.common.create_url(
@ -155,27 +159,27 @@ class InitSickBeard:
password=self.sso_password,
)
token = oauth_token['access_token']
r = requests.get(
response = requests.get(
url,
headers={f'Authorization': f'Bearer {token}'},
stream=True,
verify=False,
)
else:
r = requests.get(
response = requests.get(
url,
params=api_params,
stream=True,
verify=False,
)
if not r.ok:
logger.warning(
if not response.ok:
log.warning(
f'Connection to {self.section}:{self.input_category} '
f'failed! Check your configuration',
)
except requests.ConnectionError:
logger.warning(
log.warning(
f'Could not connect to {self.section}:'
f'{self.input_category} to verify API version!',
)
@ -197,9 +201,7 @@ class InitSickBeard:
elif self.fork == 'auto':
self.detect_fork()
logger.info(
f'{self.section}:{self.input_category} fork set to {self.fork[0]}',
)
log.info(f'{self.section}:{self.input_category} fork set to {self.fork[0]}')
nzb2media.FORK_SET = self.fork
self.fork, self.fork_params = self.fork[0], self.fork[1]
# This will create the fork object, and attach to self.fork_obj.
@ -211,15 +213,15 @@ class InitSickBeard:
try:
json_data = r.json()
except ValueError:
logger.error('Failed to get JSON data from response')
logger.debug('Response received')
log.error('Failed to get JSON data from response')
log.debug('Response received')
raise
try:
json_data = json_data['data']
except KeyError:
logger.error('Failed to get data from JSON')
logger.debug(f'Response received: {json_data}')
log.error('Failed to get data from JSON')
log.debug(f'Response received: {json_data}')
raise
else:
if isinstance(json_data, str):
@ -231,13 +233,11 @@ class InitSickBeard:
# Find excess parameters
excess_parameters = set(params).difference(optional_parameters)
excess_parameters.remove('cmd') # Don't remove cmd from api params
logger.debug(
f'Removing excess parameters: ' f'{sorted(excess_parameters)}',
)
log.debug(f'Removing excess parameters: ' f'{sorted(excess_parameters)}')
rem_params.extend(excess_parameters)
return rem_params, True
except:
logger.error('Failed to identify optionalParameters')
log.error('Failed to identify optionalParameters')
return rem_params, False
def detect_fork(self):
@ -245,7 +245,7 @@ class InitSickBeard:
detected = False
params = nzb2media.ALL_FORKS
rem_params = []
logger.info(f'Attempting to auto-detect {self.input_category} fork')
log.info(f'Attempting to auto-detect {self.input_category} fork')
# Define the order to test.
# Default must be first since default fork doesn't reject parameters.
# Then in order of most unique parameters.
@ -269,7 +269,7 @@ class InitSickBeard:
# attempting to auto-detect fork
try:
s = requests.Session()
session = requests.Session()
if not self.apikey and self.username and self.password:
login = nzb2media.utils.common.create_url(
@ -282,54 +282,54 @@ class InitSickBeard:
'username': self.username,
'password': self.password,
}
r = s.get(login, verify=False, timeout=(30, 60))
if r.status_code in [401, 403] and r.cookies.get('_xsrf'):
login_params['_xsrf'] = r.cookies.get('_xsrf')
s.post(login, data=login_params, stream=True, verify=False)
r = s.get(
response = session.get(login, verify=False, timeout=(30, 60))
if response.status_code in [401, 403] and response.cookies.get('_xsrf'):
login_params['_xsrf'] = response.cookies.get('_xsrf')
session.post(login, data=login_params, stream=True, verify=False)
response = session.get(
url,
auth=(self.username, self.password),
params=api_params,
verify=False,
)
except requests.ConnectionError:
logger.info(
log.info(
f'Could not connect to {self.section}:{self.input_category} '
f'to perform auto-fork detection!',
)
r = []
response = []
if r and r.ok:
if response and response.ok:
if self.apikey:
rem_params, found = self._api_check(r, params, rem_params)
rem_params, found = self._api_check(response, params, rem_params)
if found:
params['cmd'] = 'sg.postprocess'
else: # try different api set for non-SickGear forks.
api_params = {'cmd': 'help', 'subject': 'postprocess'}
try:
if not self.apikey and self.username and self.password:
r = s.get(
response = session.get(
url,
auth=(self.username, self.password),
params=api_params,
verify=False,
)
else:
r = s.get(url, params=api_params, verify=False)
response = session.get(url, params=api_params, verify=False)
except requests.ConnectionError:
logger.info(
log.info(
f'Could not connect to {self.section}:'
f'{self.input_category} to perform auto-fork '
f'detection!',
)
rem_params, found = self._api_check(r, params, rem_params)
rem_params, found = self._api_check(response, params, rem_params)
params['cmd'] = 'postprocess'
else:
# Find excess parameters
rem_params.extend(
param
for param in params
if f'name="{param}"' not in r.text
if f'name="{param}"' not in response.text
)
# Remove excess params
@ -343,18 +343,18 @@ class InitSickBeard:
if detected:
self.fork = fork
logger.info(
log.info(
f'{self.section}:{self.input_category} fork auto-detection '
f'successful ...',
)
elif rem_params:
logger.info(
log.info(
f'{self.section}:{self.input_category} fork auto-detection '
f'found custom params {params}',
)
self.fork = ['custom', params]
else:
logger.info(
log.info(
f'{self.section}:{self.input_category} fork auto-detection '
f'failed',
)
@ -371,12 +371,12 @@ class InitSickBeard:
'Medusa-api': PyMedusaApiV1,
'Medusa-apiv2': PyMedusaApiV2,
}
logger.debug(f'Create object for fork {self.fork}')
log.debug(f'Create object for fork {self.fork}')
if self.fork and mapped_forks.get(self.fork):
# Create the fork object and pass self (SickBeardInit) to it for all the data, like Config.
self.fork_obj = mapped_forks[self.fork](self)
else:
logger.info(
log.info(
f'{self.section}:{self.input_category} Could not create a '
f'fork object for {self.fork}. Probaly class not added yet.',
)
@ -537,10 +537,7 @@ class SickBeard:
def api_call(self) -> ProcessResult:
"""Perform a base sickbeard api call."""
self._process_fork_prarams()
logger.debug(
f'Opening URL: {self.url} with params: {self.sb_init.fork_params}',
self.sb_init.section,
)
log.debug(f'Opening URL: {self.url} with params: {self.sb_init.fork_params}')
try:
if (
not self.sb_init.apikey
@ -559,9 +556,9 @@ class SickBeard:
'username': self.sb_init.username,
'password': self.sb_init.password,
}
r = self.session.get(login, verify=False, timeout=(30, 60))
if r.status_code in [401, 403] and r.cookies.get('_xsrf'):
login_params['_xsrf'] = r.cookies.get('_xsrf')
response = self.session.get(login, verify=False, timeout=(30, 60))
if response.status_code in [401, 403] and response.cookies.get('_xsrf'):
login_params['_xsrf'] = response.cookies.get('_xsrf')
self.session.post(
login,
data=login_params,
@ -578,10 +575,7 @@ class SickBeard:
timeout=(30, 1800),
)
except requests.ConnectionError:
logger.error(
f'Unable to open URL: {self.url}',
self.sb_init.section,
)
log.error(f'Unable to open URL: {self.url}')
result = ProcessResult.failure(
f'{self.sb_init.section}: Failed to post-process - Unable to '
f'connect to {self.sb_init.section}',
@ -593,10 +587,7 @@ class SickBeard:
requests.codes.accepted,
]
if response.status_code not in successful_statuses:
logger.error(
f'Server returned status {response.status_code}',
self.sb_init.section,
)
log.error(f'Server returned status {response.status_code}')
result = ProcessResult.failure(
f'{self.sb_init.section}: Failed to post-process - Server '
f'returned status {response.status_code}',
@ -614,7 +605,7 @@ class SickBeard:
for line in response.iter_lines():
if line:
line = line.decode('utf-8')
logger.postprocess(line, self.sb_init.section)
log.postprocess(line)
# if 'Moving file from' in line:
# input_name = os.path.split(line)[1]
# if 'added to the queue' in line:

13
nzb2media/plugins/plex.py
View file

@ -1,9 +1,14 @@
from __future__ import annotations
import logging
import requests
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def configure_plex(config):
nzb2media.PLEX_SSL = int(config['Plex']['plex_ssl'])
@ -35,9 +40,7 @@ def plex_update(category):
section = None
if not nzb2media.PLEX_SECTION:
return
logger.debug(
f'Attempting to update Plex Library for category {category}.', 'PLEX',
)
log.debug(f'Attempting to update Plex Library for category {category}.')
for item in nzb2media.PLEX_SECTION:
if item[0] == category:
section = item[1]
@ -45,6 +48,6 @@ def plex_update(category):
if section:
url = f'{url}{section}/refresh?X-Plex-Token={nzb2media.PLEX_TOKEN}'
requests.get(url, timeout=(60, 120), verify=False)
logger.debug('Plex Library has been refreshed.', 'PLEX')
log.debug('Plex Library has been refreshed.')
else:
logger.debug('Could not identify section for plex update', 'PLEX')
log.debug('Could not identify section for plex update')

25
nzb2media/plugins/subtitles.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import re
@ -8,6 +9,9 @@ from babelfish import Language
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def import_subs(filename):
if not nzb2media.GETSUBS:
@ -28,9 +32,7 @@ def import_subs(filename):
if not languages:
return
logger.info(
f'Attempting to download subtitles for {filename}', 'SUBTITLES',
)
log.info(f'Attempting to download subtitles for {filename}')
try:
video = subliminal.scan_video(filename)
subtitles = subliminal.download_best_subtitles({video}, languages)
@ -41,11 +43,8 @@ def import_subs(filename):
video.name, subtitle.language,
)
os.chmod(subtitle_path, 0o644)
except Exception as e:
logger.error(
f'Failed to download subtitles for {filename} due to: {e}',
'SUBTITLES',
)
except Exception as error:
log.error(f'Failed to download subtitles for {filename} due to: {error}')
def rename_subs(path):
@ -109,16 +108,12 @@ def rename_subs(path):
break
new_sub = f'{new_sub}{ext}' # add extension now
if os.path.isfile(new_sub): # Don't copy over existing - final check.
logger.debug(
f'Unable to rename sub file {sub} as destination {new_sub} already exists',
)
log.debug(f'Unable to rename sub file {sub} as destination {new_sub} already exists')
continue
logger.debug(
f'Renaming sub file from {sub} to {new_sub}',
)
log.debug(f'Renaming sub file from {sub} to {new_sub}')
renamed.append(new_sub)
try:
os.rename(sub, new_sub)
except Exception as error:
logger.error(f'Unable to rename sub file due to: {error}')
log.error(f'Unable to rename sub file due to: {error}')
return

30
nzb2media/processor/manual.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import nzb2media
@ -8,12 +9,13 @@ from nzb2media.processor import nzb
from nzb2media.utils.common import get_dirs
from nzb2media.utils.download_info import get_download_info
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process():
# Perform Manual Post-Processing
logger.warning(
'Invalid number of arguments received from client, Switching to manual run mode ...',
)
log.warning('Invalid number of arguments received from client, Switching to manual run mode ...')
# Post-Processing Result
result = ProcessResult(
@ -26,29 +28,21 @@ def process():
if not nzb2media.CFG[section][subsection].isenabled():
continue
for dir_name in get_dirs(section, subsection, link='move'):
logger.info(
f'Starting manual run for {section}:{subsection} - Folder: {dir_name}',
)
logger.info(
f'Checking database for download info for {os.path.basename(dir_name)} ...',
)
log.info(f'Starting manual run for {section}:{subsection} - Folder: {dir_name}')
log.info(f'Checking database for download info for {os.path.basename(dir_name)} ...')
nzb2media.DOWNLOAD_INFO = get_download_info(
os.path.basename(dir_name),
0,
)
if nzb2media.DOWNLOAD_INFO:
logger.info(
f'Found download info for {os.path.basename(dir_name)}, setting variables now ...',
)
log.info(f'Found download info for {os.path.basename(dir_name)}, setting variables now ...')
client_agent = (
nzb2media.DOWNLOAD_INFO[0]['client_agent'] or 'manual'
nzb2media.DOWNLOAD_INFO[0]['client_agent'] or 'manual'
)
download_id = nzb2media.DOWNLOAD_INFO[0]['input_id'] or ''
else:
logger.info(
f'Unable to locate download info for {os.path.basename(dir_name)}, continuing to try and process this release ...',
)
log.info(f'Unable to locate download info for {os.path.basename(dir_name)}, continuing to try and process this release ...')
client_agent = 'manual'
download_id = ''
@ -69,8 +63,6 @@ def process():
input_category=subsection,
)
if results.status_code != 0:
logger.error(
f'A problem was reported when trying to perform a manual run for {section}:{subsection}.',
)
log.error(f'A problem was reported when trying to perform a manual run for {section}:{subsection}.')
result = results
return result

63
nzb2media/processor/nzb.py
View file

@ -1,6 +1,7 @@
from __future__ import annotations
import datetime
import logging
import nzb2media
from nzb2media import main_db
@ -20,6 +21,9 @@ from nzb2media.utils.encoding import convert_to_ascii
from nzb2media.utils.files import extract_files
from nzb2media.utils.nzb import get_nzoid
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def process(
input_directory,
@ -31,9 +35,7 @@ def process(
failure_link=None,
):
if nzb2media.SAFE_MODE and input_directory == nzb2media.NZB_DEFAULT_DIRECTORY:
logger.error(
f'The input directory:[{input_directory}] is the Default Download Directory. Please configure category directories to prevent processing of other media.',
)
log.error(f'The input directory:[{input_directory}] is the Default Download Directory. Please configure category directories to prevent processing of other media.')
return ProcessResult(
message='',
status_code=-1,
@ -41,23 +43,16 @@ def process(
if not download_id and client_agent == 'sabnzbd':
download_id = get_nzoid(input_name)
if client_agent != 'manual' and not nzb2media.DOWNLOAD_INFO:
logger.debug(
f'Adding NZB download info for directory {input_directory} to database',
)
log.debug(f'Adding NZB download info for directory {input_directory} to database')
my_db = main_db.DBConnection()
input_directory1 = input_directory
input_name1 = input_name
try:
encoded, input_directory1 = char_replace(input_directory)
encoded, input_name1 = char_replace(input_name)
except Exception:
pass
control_value_dict = {'input_directory': input_directory1}
new_value_dict = {
'input_name': input_name1,
@ -68,7 +63,6 @@ def process(
'last_update': datetime.date.today().toordinal(),
}
my_db.upsert('downloads', new_value_dict, control_value_dict)
# auto-detect section
if input_category is None:
input_category = 'UNCAT'
@ -77,68 +71,45 @@ def process(
if section is None:
section = nzb2media.CFG.findsection('ALL').isenabled()
if section is None:
logger.error(
f'Category:[{input_category}] is not defined or is not enabled. Please rename it or ensure it is enabled for the appropriate section in your autoProcessMedia.cfg and try again.',
)
log.error(f'Category:[{input_category}] is not defined or is not enabled. Please rename it or ensure it is enabled for the appropriate section in your autoProcessMedia.cfg and try again.')
return ProcessResult(
message='',
status_code=-1,
)
else:
usercat = 'ALL'
if len(section) > 1:
logger.error(
f'Category:[{input_category}] is not unique, {section.keys()} are using it. Please rename it or disable all other sections using the same category name in your autoProcessMedia.cfg and try again.',
)
log.error(f'Category:[{input_category}] is not unique, {section.keys()} are using it. Please rename it or disable all other sections using the same category name in your autoProcessMedia.cfg and try again.')
return ProcessResult(
message='',
status_code=-1,
)
if section:
section_name = section.keys()[0]
logger.info(f'Auto-detected SECTION:{section_name}')
log.info(f'Auto-detected SECTION:{section_name}')
else:
logger.error(
f'Unable to locate a section with subsection:{input_category} enabled in your autoProcessMedia.cfg, exiting!',
)
log.error(f'Unable to locate a section with subsection:{input_category} enabled in your autoProcessMedia.cfg, exiting!')
return ProcessResult(
status_code=-1,
message='',
)
cfg = dict(nzb2media.CFG[section_name][usercat])
extract = int(cfg.get('extract', 0))
try:
if int(cfg.get('remote_path')) and not nzb2media.REMOTE_PATHS:
logger.error(
f'Remote Path is enabled for {section_name}:{input_category} but no Network mount points are defined. Please check your autoProcessMedia.cfg, exiting!',
)
log.error(f'Remote Path is enabled for {section_name}:{input_category} but no Network mount points are defined. Please check your autoProcessMedia.cfg, exiting!')
return ProcessResult(
status_code=-1,
message='',
)
except Exception:
remote_path = cfg.get('remote_path')
logger.error(
f'Remote Path {remote_path} is not valid for {section_name}:{input_category} Please set this to either 0 to disable or 1 to enable!',
)
log.error(f'Remote Path {remote_path} is not valid for {section_name}:{input_category} Please set this to either 0 to disable or 1 to enable!')
input_name, input_directory = convert_to_ascii(input_name, input_directory)
if extract == 1 and not (status > 0 and nzb2media.NOEXTRACTFAILED):
logger.debug(
f'Checking for archives to extract in directory: {input_directory}',
)
log.debug(f'Checking for archives to extract in directory: {input_directory}')
extract_files(input_directory)
logger.info(
f'Calling {section_name}:{input_category} to post-process:{input_name}',
)
log.info(f'Calling {section_name}:{input_category} to post-process:{input_name}')
if section_name == 'UserScript':
result = external_script(
input_directory, input_name, input_category, section[usercat],
@ -169,9 +140,7 @@ def process(
input_category=input_category,
failure_link=failure_link,
)
plex_update(input_category)
if result.status_code == 0:
if client_agent != 'manual':
# update download status in our DB
@ -183,7 +152,7 @@ def process(
'Radarr',
'Lidarr',
]:
# cleanup our processing folders of any misc unwanted files and empty directories
# cleanup our processing folders of any misc unwanted files and
# empty directories
clean_dir(input_directory, section_name, input_category)
return result

28
nzb2media/processor/nzbget.py
View file

@ -1,11 +1,15 @@
from __future__ import annotations
import logging
import os
import sys
import nzb2media
from nzb2media.processor import nzb
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def parse_download_id():
"""Parse nzbget download_id from environment."""
@ -34,7 +38,7 @@ def _parse_total_status():
status_summary = os.environ['NZBPP_TOTALSTATUS']
if status_summary != 'SUCCESS':
status = os.environ['NZBPP_STATUS']
logger.info(f'Download failed with status {status}.')
log.info(f'Download failed with status {status}.')
return 1
return 0
@ -43,14 +47,14 @@ def _parse_par_status():
"""Parse nzbget par status from environment."""
par_status = os.environ['NZBPP_PARSTATUS']
if par_status == '1' or par_status == '4':
logger.warning('Par-repair failed, setting status \'failed\'')
log.warning('Par-repair failed, setting status \'failed\'')
return 1
return 0
def _parse_unpack_status():
if os.environ['NZBPP_UNPACKSTATUS'] == '1':
logger.warning('Unpack failed, setting status \'failed\'')
log.warning('Unpack failed, setting status \'failed\'')
return 1
return 0
@ -64,17 +68,11 @@ def _parse_health_status():
# Unpack was skipped due to nzb-file properties
# or due to errors during par-check
if int(os.environ['NZBPP_HEALTH']) < 1000:
logger.warning(
'Download health is compromised and Par-check/repair disabled or no .par2 files found. Setting status \'failed\'',
)
log.warning('Download health is compromised and Par-check/repair disabled or no .par2 files found. Setting status \'failed\'')
status = 1
else:
logger.info(
'Par-check/repair disabled or no .par2 files found, and Unpack not required. Health is ok so handle as though download successful',
)
logger.info(
'Please check your Par-check/repair settings for future downloads.',
)
log.info('Par-check/repair disabled or no .par2 files found, and Unpack not required. Health is ok so handle as though download successful')
log.info('Please check your Par-check/repair settings for future downloads.')
return status
@ -94,11 +92,9 @@ def check_version():
version = os.environ['NZBOP_VERSION']
# Check if the script is called from nzbget 11.0 or later
if version[0:5] < '11.0':
logger.error(
f'NZBGet Version {version} is not supported. Please update NZBGet.',
)
log.error(f'NZBGet Version {version} is not supported. Please update NZBGet.')
sys.exit(nzb2media.NZBGET_POSTPROCESS_ERROR)
logger.info(f'Script triggered from NZBGet Version {version}.')
log.info(f'Script triggered from NZBGet Version {version}.')
def process():

9
nzb2media/processor/sab.py
View file

@ -1,16 +1,19 @@
from __future__ import annotations
import logging
import os
from nzb2media.processor import nzb
# Constants
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
MINIMUM_ARGUMENTS = 8
def process_script():
version = os.environ['SAB_VERSION']
logger.info(f'Script triggered from SABnzbd {version}.')
log.info(f'Script triggered from SABnzbd {version}.')
return nzb.process(
input_directory=os.environ['SAB_COMPLETE_DIR'],
input_name=os.environ['SAB_FINAL_NAME'],
@ -39,7 +42,7 @@ def process(args):
8. Failure URL
"""
version = '0.7.17+' if len(args) > MINIMUM_ARGUMENTS else ''
logger.info(f'Script triggered from SABnzbd {version}')
log.info(f'Script triggered from SABnzbd {version}')
return nzb.process(
input_directory=args[1],
input_name=args[2],

50
nzb2media/scene_exceptions.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import platform
import re
@ -9,6 +10,10 @@ import subprocess
import nzb2media
from nzb2media.utils.files import list_media_files
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
reverse_list = [
r'\.\d{2}e\d{2}s\.',
r'\.[pi]0801\.',
@ -112,14 +117,11 @@ def rename_file(filename, newfile_path):
+ '.NTM'
+ os.path.splitext(newfile_path)[1]
)
logger.debug(
f'Replacing file name {filename} with download name {newfile_path}',
'EXCEPTION',
)
log.error(f'Replacing file name {filename} with download name {newfile_path}')
try:
os.rename(filename, newfile_path)
except Exception as error:
logger.error(f'Unable to rename file due to: {error}', 'EXCEPTION')
log.error(f'Unable to rename file due to: {error}')
def replace_filename(filename, dirname, name):
@ -129,20 +131,12 @@ def replace_filename(filename, dirname, name):
is not None
):
newname = os.path.basename(dirname).replace(' ', '.')
logger.debug(
f'Replacing file name {head} with directory name {newname}',
'EXCEPTION',
)
log.debug(f'Replacing file name {head} with directory name {newname}')
elif media_pattern.search(name.replace(' ', '.').lower()) is not None:
newname = name.replace(' ', '.')
logger.debug(
f'Replacing file name {head} with download name {newname}',
'EXCEPTION',
)
log.debug(f'Replacing file name {head} with download name {newname}')
else:
logger.warning(
f'No name replacement determined for {head}', 'EXCEPTION',
)
log.warning(f'No name replacement determined for {head}')
newname = name
newfile = newname + file_extension
newfile_path = os.path.join(dirname, newfile)
@ -168,10 +162,7 @@ def reverse_filename(filename, dirname, name):
else:
newname = head[::-1].title()
newname = newname.replace(' ', '.')
logger.debug(
f'Reversing filename {head} to {newname}',
'EXCEPTION',
)
log.debug(f'Reversing filename {head} to {newname}')
newfile = newname + file_extension
newfile_path = os.path.join(dirname, newfile)
return newfile_path
@ -199,16 +190,11 @@ def rename_script(dirname):
)
if os.path.isfile(dest):
continue
logger.debug(
f'Renaming file {orig} to {dest}',
'EXCEPTION',
)
log.debug(f'Renaming file {orig} to {dest}')
try:
os.rename(orig, dest)
except Exception as error:
logger.error(
f'Unable to rename file due to: {error}', 'EXCEPTION',
)
log.error(f'Unable to rename file due to: {error}')
def par2(dirname):
@ -230,12 +216,12 @@ def par2(dirname):
bitbucket = open('NUL')
else:
bitbucket = open('/dev/null')
logger.info(f'Running par2 on file {parfile}.', 'PAR2')
log.info(f'Running par2 on file {parfile}.')
command = [nzb2media.PAR2CMD, 'r', parfile, '*']
cmd = ''
for item in command:
cmd = f'{cmd} {item}'
logger.debug(f'calling command:{cmd}', 'PAR2')
log.debug(f'calling command:{cmd}')
try:
proc = subprocess.Popen(
command, stdout=bitbucket, stderr=bitbucket,
@ -243,11 +229,9 @@ def par2(dirname):
proc.communicate()
result = proc.returncode
except Exception:
logger.error(
f'par2 file processing for {parfile} has failed', 'PAR2',
)
log.error(f'par2 file processing for {parfile} has failed')
if result == 0:
logger.info('par2 file processing succeeded', 'PAR2')
log.info('par2 file processing succeeded')
os.chdir(pwd)
bitbucket.close()

9
nzb2media/torrent/deluge.py
View file

@ -1,9 +1,14 @@
from __future__ import annotations
import logging
from deluge_client import DelugeRPCClient
import nzb2media
log = logging.getLogger()
log.addHandler(logging.NullHandler())
def configure_client():
agent = 'deluge'
@ -12,11 +17,11 @@ def configure_client():
user = nzb2media.DELUGE_USER
password = nzb2media.DELUGE_PASSWORD
logger.debug(f'Connecting to {agent}: http://{host}:{port}')
log.debug(f'Connecting to {agent}: http://{host}:{port}')
client = DelugeRPCClient(host, port, user, password)
try:
client.connect()
except Exception:
logger.error('Failed to connect to Deluge')
log.error('Failed to connect to Deluge')
else:
return client

11
nzb2media/torrent/qbittorrent.py
View file

@ -1,9 +1,14 @@
from __future__ import annotations
import logging
from qbittorrent import Client as qBittorrentClient
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def configure_client():
agent = 'qbittorrent'
@ -12,13 +17,11 @@ def configure_client():
user = nzb2media.QBITTORRENT_USER
password = nzb2media.QBITTORRENT_PASSWORD
logger.debug(
f'Connecting to {agent}: http://{host}:{port}',
)
log.debug(f'Connecting to {agent}: http://{host}:{port}')
client = qBittorrentClient(f'http://{host}:{port}/')
try:
client.login(user, password)
except Exception:
logger.error('Failed to connect to qBittorrent')
log.error('Failed to connect to qBittorrent')
else:
return client

8
nzb2media/torrent/synology.py
View file

@ -1,9 +1,13 @@
from __future__ import annotations
import logging
from syno.downloadstation import DownloadStation
import nzb2media
log = logging.getLogger(__name__)
def configure_client():
agent = 'synology'
@ -12,10 +16,10 @@ def configure_client():
user = nzb2media.SYNO_USER
password = nzb2media.SYNO_PASSWORD
logger.debug(f'Connecting to {agent}: http://{host}:{port}')
log.debug(f'Connecting to {agent}: http://{host}:{port}')
try:
client = DownloadStation(host, port, user, password)
except Exception:
logger.error('Failed to connect to synology')
log.error('Failed to connect to synology')
else:
return client

9
nzb2media/torrent/transmission.py
View file

@ -1,9 +1,14 @@
from __future__ import annotations
import logging
from transmissionrpc.client import Client as TransmissionClient
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def configure_client():
agent = 'transmission'
@ -12,10 +17,10 @@ def configure_client():
user = nzb2media.TRANSMISSION_USER
password = nzb2media.TRANSMISSION_PASSWORD
logger.debug(f'Connecting to {agent}: http://{host}:{port}')
log.debug(f'Connecting to {agent}: http://{host}:{port}')
try:
client = TransmissionClient(host, port, user, password)
except Exception:
logger.error('Failed to connect to Transmission')
log.error('Failed to connect to Transmission')
else:
return client

9
nzb2media/torrent/utorrent.py
View file

@ -1,9 +1,14 @@
from __future__ import annotations
import logging
from utorrent.client import UTorrentClient
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def configure_client():
agent = 'utorrent'
@ -11,10 +16,10 @@ def configure_client():
user = nzb2media.UTORRENT_USER
password = nzb2media.UTORRENT_PASSWORD
logger.debug(f'Connecting to {agent}: {web_ui}')
log.debug(f'Connecting to {agent}: {web_ui}')
try:
client = UTorrentClient(web_ui, user, password)
except Exception:
logger.error('Failed to connect to uTorrent')
log.error('Failed to connect to uTorrent')
else:
return client

137
nzb2media/transcoder.py
View file

@ -2,6 +2,7 @@ from __future__ import annotations
import errno
import json
import logging
import os
import pathlib
import platform
@ -16,6 +17,9 @@ from babelfish import Language
import nzb2media
from nzb2media.utils.paths import make_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
__author__ = 'Justin'
@ -34,10 +38,7 @@ def is_video_good(video: pathlib.Path, status, require_lan=None):
test_details, res = get_video_details(nzb2media.TEST_FILE)
if res != 0 or test_details.get('error'):
disable = True
logger.info(
'DISABLED: ffprobe failed to analyse test file. Stopping corruption check.',
'TRANSCODER',
)
log.info('DISABLED: ffprobe failed to analyse test file. Stopping corruption check.')
if test_details.get('streams'):
vid_streams = [
item
@ -51,10 +52,7 @@ def is_video_good(video: pathlib.Path, status, require_lan=None):
]
if not (len(vid_streams) > 0 and len(aud_streams) > 0):
disable = True
logger.info(
'DISABLED: ffprobe failed to analyse streams from test file. Stopping corruption check.',
'TRANSCODER',
)
log.info('DISABLED: ffprobe failed to analyse streams from test file. Stopping corruption check.')
if disable:
if status:
# if the download was 'failed', assume bad.
@ -63,21 +61,15 @@ def is_video_good(video: pathlib.Path, status, require_lan=None):
else:
return True
logger.info(
f'Checking [{video.name}] for corruption, please stand by ...',
'TRANSCODER',
)
log.info(f'Checking [{video.name}] for corruption, please stand by ...')
video_details, result = get_video_details(video)
if result != 0:
logger.error(f'FAILED: [{video.name}] is corrupted!', 'TRANSCODER')
log.error(f'FAILED: [{video.name}] is corrupted!')
return False
if video_details.get('error'):
error_details = video_details.get('error')
logger.info(
f'FAILED: [{video.name}] returned error [{error_details}].',
'TRANSCODER',
)
log.info(f'FAILED: [{video.name}] returned error [{error_details}].')
return False
if video_details.get('streams'):
video_streams = [
@ -101,15 +93,10 @@ def is_video_good(video: pathlib.Path, status, require_lan=None):
else:
valid_audio = audio_streams
if len(video_streams) > 0 and len(valid_audio) > 0:
logger.info(
f'SUCCESS: [{video.name}] has no corruption.', 'TRANSCODER',
)
log.info(f'SUCCESS: [{video.name}] has no corruption.')
return True
else:
logger.info(
f'FAILED: [{video.name}] has {len(video_streams)} video streams and {len(audio_streams)} audio streams. Assume corruption.',
'TRANSCODER',
)
log.info(f'FAILED: [{video.name}] has {len(video_streams)} video streams and {len(audio_streams)} audio streams. Assume corruption.')
return False
@ -124,7 +111,7 @@ def zip_out(file, img, bitbucket):
cmd, stdout=subprocess.PIPE, stderr=bitbucket,
)
except Exception:
logger.error(f'Extracting [{file}] has failed', 'TRANSCODER')
log.error(f'Extracting [{file}] has failed')
return procin
@ -186,7 +173,7 @@ def get_video_details(videofile, img=None, bitbucket=None):
result = proc.returncode
video_details = json.loads(out.decode())
except Exception:
logger.error(f'Checking [{file}] has failed', 'TRANSCODER')
log.error(f'Checking [{file}] has failed')
return video_details, result
@ -781,9 +768,9 @@ def extract_subs(file, newfile_path, bitbucket):
item
for item in video_details['streams']
if item['codec_type'] == 'subtitle'
and item['tags']['language'] in nzb2media.SLANGUAGES
and item['codec_name'] != 'hdmv_pgs_subtitle'
and item['codec_name'] != 'pgssub'
and item['tags']['language'] in nzb2media.SLANGUAGES
and item['codec_name'] != 'hdmv_pgs_subtitle'
and item['codec_name'] != 'pgssub'
]
except Exception:
sub_streams = [
@ -823,7 +810,7 @@ def extract_subs(file, newfile_path, bitbucket):
if platform.system() != 'Windows':
command = nzb2media.NICENESS + command
logger.info(f'Extracting {lan} subtitle from: {file}')
log.info(f'Extracting {lan} subtitle from: {file}')
print_cmd(command)
result = 1 # set result to failed in case call fails.
try:
@ -833,16 +820,16 @@ def extract_subs(file, newfile_path, bitbucket):
out, err = proc.communicate()
result = proc.returncode
except Exception:
logger.error('Extracting subtitle has failed')
log.error('Extracting subtitle has failed')
if result == 0:
try:
shutil.copymode(file, output_file)
except Exception:
pass
logger.info(f'Extracting {lan} subtitle from {file} has succeeded')
log.info(f'Extracting {lan} subtitle from {file} has succeeded')
else:
logger.error('Extracting subtitles has failed')
log.error('Extracting subtitles has failed')
def process_list(it, new_dir, bitbucket):
@ -858,14 +845,14 @@ def process_list(it, new_dir, bitbucket):
ext in ['.iso', '.bin', '.img']
and ext not in nzb2media.IGNOREEXTENSIONS
):
logger.debug(f'Attempting to rip disk image: {item}', 'TRANSCODER')
log.debug(f'Attempting to rip disk image: {item}')
new_list.extend(rip_iso(item, new_dir, bitbucket))
rem_list.append(item)
elif (
re.match('.+VTS_[0-9][0-9]_[0-9].[Vv][Oo][Bb]', item)
and '.vob' not in nzb2media.IGNOREEXTENSIONS
):
logger.debug(f'Found VIDEO_TS image file: {item}', 'TRANSCODER')
log.debug(f'Found VIDEO_TS image file: {item}')
if not vts_path:
try:
vts_path = re.match('(.+VIDEO_TS)', item).groups()[0]
@ -876,7 +863,7 @@ def process_list(it, new_dir, bitbucket):
re.match('.+BDMV[/\\]SOURCE[/\\][0-9]+[0-9].[Mm][Tt][Ss]', item)
and '.mts' not in nzb2media.IGNOREEXTENSIONS
):
logger.debug(f'Found MTS image file: {item}', 'TRANSCODER')
log.debug(f'Found MTS image file: {item}')
if not mts_path:
try:
mts_path = re.match('(.+BDMV[/\\]SOURCE)', item).groups()[
@ -912,17 +899,11 @@ def process_list(it, new_dir, bitbucket):
it.extend(new_list)
for item in rem_list:
it.remove(item)
logger.debug(
f'Successfully extracted .vob file {new_list[0]} from disk image',
'TRANSCODER',
)
log.debug(f'Successfully extracted .vob file {new_list[0]} from disk image')
elif new_list and not success:
new_list = []
rem_list = []
logger.error(
'Failed extracting .vob files from disk image. Stopping transcoding.',
'TRANSCODER',
)
log.error('Failed extracting .vob files from disk image. Stopping transcoding.')
return it, rem_list, new_list, success
@ -930,10 +911,7 @@ def mount_iso(
item, new_dir, bitbucket,
): # Currently only supports Linux Mount when permissions allow.
if platform.system() == 'Windows':
logger.error(
f'No mounting options available under Windows for image file {item}',
'TRANSCODER',
)
log.error(f'No mounting options available under Windows for image file {item}')
return []
mount_point = os.path.join(os.path.dirname(os.path.abspath(item)), 'temp')
make_dir(mount_point)
@ -951,9 +929,7 @@ def mount_iso(
re.match('.+VTS_[0-9][0-9]_[0-9].[Vv][Oo][Bb]', full_path)
and '.vob' not in nzb2media.IGNOREEXTENSIONS
):
logger.debug(
f'Found VIDEO_TS image file: {full_path}', 'TRANSCODER',
)
log.debug(f'Found VIDEO_TS image file: {full_path}')
try:
vts_path = re.match('(.+VIDEO_TS)', full_path).groups()[0]
except Exception:
@ -963,9 +939,7 @@ def mount_iso(
re.match('.+BDMV[/\\]STREAM[/\\][0-9]+[0-9].[Mm]', full_path)
and '.mts' not in nzb2media.IGNOREEXTENSIONS
):
logger.debug(
f'Found MTS image file: {full_path}', 'TRANSCODER',
)
log.debug(f'Found MTS image file: {full_path}')
try:
mts_path = re.match(
'(.+BDMV[/\\]STREAM)', full_path,
@ -973,10 +947,7 @@ def mount_iso(
except Exception:
mts_path = os.path.split(full_path)[0]
return combine_mts(mts_path)
logger.error(
f'No VIDEO_TS or BDMV/SOURCE folder found in image file {mount_point}',
'TRANSCODER',
)
log.error(f'No VIDEO_TS or BDMV/SOURCE folder found in image file {mount_point}')
return ['failure'] # If we got here, nothing matched our criteria
@ -985,27 +956,18 @@ def rip_iso(item, new_dir, bitbucket):
failure_dir = 'failure'
# Mount the ISO in your OS and call combineVTS.
if not nzb2media.SEVENZIP:
logger.debug(
f'No 7zip installed. Attempting to mount image file {item}',
'TRANSCODER',
)
log.debug(f'No 7zip installed. Attempting to mount image file {item}')
try:
new_files = mount_iso(
item, new_dir, bitbucket,
) # Currently only works for Linux.
except Exception:
logger.error(
f'Failed to mount and extract from image file {item}',
'TRANSCODER',
)
log.error(f'Failed to mount and extract from image file {item}')
new_files = [failure_dir]
return new_files
cmd = [nzb2media.SEVENZIP, 'l', item]
try:
logger.debug(
f'Attempting to extract .vob or .mts from image file {item}',
'TRANSCODER',
)
log.debug(f'Attempting to extract .vob or .mts from image file {item}')
print_cmd(cmd)
proc = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=bitbucket)
out, err = proc.communicate()
@ -1077,13 +1039,10 @@ def rip_iso(item, new_dir, bitbucket):
name = os.path.splitext(os.path.split(item)[1])[0]
new_files.append({item: {'name': name, 'files': combined}})
if not new_files:
logger.error(
f'No VIDEO_TS or BDMV/SOURCE folder found in image file. Attempting to mount and scan {item}',
'TRANSCODER',
)
log.error(f'No VIDEO_TS or BDMV/SOURCE folder found in image file. Attempting to mount and scan {item}')
new_files = mount_iso(item, new_dir, bitbucket)
except Exception:
logger.error(f'Failed to extract from image file {item}', 'TRANSCODER')
log.error(f'Failed to extract from image file {item}')
new_files = [failure_dir]
return new_files
@ -1183,13 +1142,13 @@ def print_cmd(command):
cmd = ''
for item in command:
cmd = f'{cmd} {item}'
logger.debug(f'calling command:{cmd}')
log.debug(f'calling command:{cmd}')
def transcode_directory(dir_name):
if not nzb2media.FFMPEG:
return 1, dir_name
logger.info('Checking for files to be transcoded')
log.info('Checking for files to be transcoded')
final_result = 0 # initialize as successful
if nzb2media.OUTPUTVIDEOPATH:
new_dir = nzb2media.OUTPUTVIDEOPATH
@ -1229,15 +1188,15 @@ def transcode_directory(dir_name):
try: # Try to remove the file that we're transcoding to just in case. (ffmpeg will return an error if it already exists for some reason)
os.remove(newfile_path)
except OSError as e:
except OSError as error:
if (
e.errno != errno.ENOENT
error.errno != errno.ENOENT
): # Ignore the error if it's just telling us that the file doesn't exist
logger.debug(f'Error when removing transcoding target: {e}')
except Exception as e:
logger.debug(f'Error when removing transcoding target: {e}')
log.debug(f'Error when removing transcoding target: {error}')
except Exception as error:
log.debug(f'Error when removing transcoding target: {error}')
logger.info(f'Transcoding video: {newfile_path}')
log.info(f'Transcoding video: {newfile_path}')
print_cmd(command)
result = 1 # set result to failed in case call fails.
try:
@ -1256,15 +1215,15 @@ def transcode_directory(dir_name):
for vob in data['files']:
procin = zip_out(vob, img, bitbucket)
if procin:
logger.debug(f'Feeding in file: {vob} to Transcoder')
log.debug(f'Feeding in file: {vob} to Transcoder')
shutil.copyfileobj(procin.stdout, proc.stdin)
procin.stdout.close()
out, err = proc.communicate()
if err:
logger.error(f'Transcoder returned:{err} has failed')
log.error(f'Transcoder returned:{err} has failed')
result = proc.returncode
except Exception:
logger.error(f'Transcoding of video {newfile_path} has failed')
log.error(f'Transcoding of video {newfile_path} has failed')
if nzb2media.SUBSDIR and result == 0 and isinstance(file, str):
for sub in get_subs(file):
@ -1282,7 +1241,7 @@ def transcode_directory(dir_name):
shutil.copymode(file, newfile_path)
except Exception:
pass
logger.info(f'Transcoding of video to {newfile_path} succeeded')
log.info(f'Transcoding of video to {newfile_path} succeeded')
if os.path.isfile(newfile_path) and (
file in new_list or not nzb2media.DUPLICATE
):
@ -1291,9 +1250,7 @@ def transcode_directory(dir_name):
except Exception:
pass
else:
logger.error(
f'Transcoding of video to {newfile_path} failed with result {result}',
)
log.error(f'Transcoding of video to {newfile_path} failed with result {result}')
# this will be 0 (successful) it all are successful, else will return a positive integer for failure.
final_result = final_result + result
if nzb2media.MOUNTED: # In case we mounted an .iso file, unmount here.

50
nzb2media/user_scripts.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
from subprocess import Popen
@ -10,6 +11,9 @@ from nzb2media.plugins.subtitles import import_subs
from nzb2media.utils.files import list_media_files
from nzb2media.utils.paths import remove_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def external_script(output_destination, torrent_name, torrent_label, settings):
final_result = 0 # start at 0.
@ -23,9 +27,7 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
nzb2media.USER_SCRIPT_MEDIAEXTENSIONS.lower().split(',')
)
except Exception:
logger.error(
'user_script_mediaExtensions could not be set', 'USERSCRIPT',
)
log.error('user_script_mediaExtensions could not be set')
nzb2media.USER_SCRIPT_MEDIAEXTENSIONS = []
nzb2media.USER_SCRIPT = settings.get('user_script_path', '')
@ -42,7 +44,7 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
if isinstance(nzb2media.USER_SCRIPT_PARAM, str):
nzb2media.USER_SCRIPT_PARAM = nzb2media.USER_SCRIPT_PARAM.split(',')
except Exception:
logger.error('user_script_params could not be set', 'USERSCRIPT')
log.error('user_script_params could not be set')
nzb2media.USER_SCRIPT_PARAM = []
nzb2media.USER_SCRIPT_SUCCESSCODES = settings.get('user_script_successCodes', 0)
@ -52,7 +54,7 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
nzb2media.USER_SCRIPT_SUCCESSCODES.split(',')
)
except Exception:
logger.error('user_script_successCodes could not be set', 'USERSCRIPT')
log.error('user_script_successCodes could not be set')
nzb2media.USER_SCRIPT_SUCCESSCODES = 0
nzb2media.USER_SCRIPT_CLEAN = int(settings.get('user_script_clean', 1))
@ -69,10 +71,7 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
if transcoder.is_video_good(video, 0):
import_subs(video)
else:
logger.info(
f'Corrupt video file found {video}. Deleting.',
'USERSCRIPT',
)
log.info(f'Corrupt video file found {video}. Deleting.')
os.unlink(video)
for dirpath, _, filenames in os.walk(output_destination):
@ -80,10 +79,7 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
file_path = nzb2media.os.path.join(dirpath, file)
file_name, file_extension = os.path.splitext(file)
logger.debug(
f'Checking file {file} to see if this should be processed.',
'USERSCRIPT',
)
log.debug(f'Checking file {file} to see if this should be processed.')
if (
file_extension in nzb2media.USER_SCRIPT_MEDIAEXTENSIONS
@ -120,31 +116,21 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
cmd = ''
for item in command:
cmd = f'{cmd} {item}'
logger.info(
f'Running script {cmd} on file {file_path}.', 'USERSCRIPT',
)
log.info(f'Running script {cmd} on file {file_path}.')
try:
p = Popen(command)
res = p.wait()
if (
str(res) in nzb2media.USER_SCRIPT_SUCCESSCODES
): # Linux returns 0 for successful.
logger.info(f'UserScript {command[0]} was successfull')
log.info(f'UserScript {command[0]} was successfull')
result = 0
else:
logger.error(
f'UserScript {command[0]} has failed with return code: {res}',
'USERSCRIPT',
)
logger.info(
f'If the UserScript completed successfully you should add {res} to the user_script_successCodes',
'USERSCRIPT',
)
log.error(f'UserScript {command[0]} has failed with return code: {res}')
log.info(f'If the UserScript completed successfully you should add {res} to the user_script_successCodes')
result = int(1)
except Exception:
logger.error(
f'UserScript {command[0]} has failed', 'USERSCRIPT',
)
log.error(f'UserScript {command[0]} has failed')
result = int(1)
final_result += result
@ -164,14 +150,10 @@ def external_script(output_destination, torrent_name, torrent_label, settings):
and num_files_new == 0
and final_result == 0
):
logger.info(
f'All files have been processed. Cleaning outputDirectory {output_destination}',
)
log.info(f'All files have been processed. Cleaning outputDirectory {output_destination}')
remove_dir(output_destination)
elif nzb2media.USER_SCRIPT_CLEAN == int(1) and num_files_new != 0:
logger.info(
f'{num_files} files were processed, but {num_files_new} still remain. outputDirectory will not be cleaned.',
)
log.info(f'{num_files} files were processed, but {num_files_new} still remain. outputDirectory will not be cleaned.')
return ProcessResult(
status_code=final_result,
message='User Script Completed',

32
nzb2media/utils/common.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os.path
import urllib.parse
@ -9,6 +10,9 @@ from nzb2media.utils.files import move_file
from nzb2media.utils.paths import clean_directory
from nzb2media.utils.paths import flatten_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def flatten(output_destination):
return flatten_dir(
@ -32,7 +36,7 @@ def clean_dir(path, section, subsection):
def process_dir(path, link):
folders = []
logger.info(f'Searching {path} for mediafiles to post-process ...')
log.info(f'Searching {path} for mediafiles to post-process ...')
dir_contents = os.listdir(path)
# search for single files and move them into their own folder for post-processing
@ -54,16 +58,12 @@ def process_dir(path, link):
# Generate a list of media files
mediafiles = (item for item in filepaths if os.path.isfile(item))
if any(sync_files):
logger.info('')
else:
if not any(sync_files):
for mediafile in mediafiles:
try:
move_file(mediafile, path, link)
except Exception as e:
logger.error(
f'Failed to move {os.path.split(mediafile)[1]} to its own directory: {e}',
)
except Exception as error:
log.error(f'Failed to move {os.path.split(mediafile)[1]} to its own directory: {error}')
# removeEmptyFolders(path, removeRoot=False)
@ -98,25 +98,19 @@ def get_dirs(section, subsection, link='hard'):
try:
to_return.extend(process_dir(directory, link))
except Exception as e:
logger.error(
f'Failed to add directories from {watch_directory} for post-processing: {e}',
)
except Exception as error:
log.error(f'Failed to add directories from {watch_directory} for post-processing: {error}')
if nzb2media.USE_LINK == 'move':
try:
output_directory = os.path.join(nzb2media.OUTPUT_DIRECTORY, subsection)
if os.path.exists(output_directory):
to_return.extend(process_dir(output_directory, link))
except Exception as e:
logger.error(
f'Failed to add directories from {nzb2media.OUTPUT_DIRECTORY} for post-processing: {e}',
)
except Exception as error:
log.error(f'Failed to add directories from {nzb2media.OUTPUT_DIRECTORY} for post-processing: {error}')
if not to_return:
logger.debug(
f'No directories identified in {section}:{subsection} for post-processing',
)
log.debug(f'No directories identified in {section}:{subsection} for post-processing')
return list(set(to_return))

10
nzb2media/utils/download_info.py
View file

@ -1,23 +1,25 @@
from __future__ import annotations
import datetime
import logging
from nzb2media import main_db
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
database = main_db.DBConnection()
def update_download_info_status(input_name, status):
msg = 'Updating DB download status of {0} to {1}'
log.debug(f'Updating DB download status of {input_name} to {status}')
action = 'UPDATE downloads SET status=?, last_update=? WHERE input_name=?'
args = [status, datetime.date.today().toordinal(), input_name]
logger.db(msg.format(input_name, status))
database.action(action, args)
def get_download_info(input_name, status):
msg = 'Getting download info for {0} from the DB'
log.debug(f'Getting download info for {input_name} from the DB')
action = 'SELECT * FROM downloads WHERE input_name=? AND status=?'
args = [input_name, status]
logger.db(msg.format(input_name))
return database.select(action, args)

12
nzb2media/utils/encoding.py
View file

@ -1,9 +1,13 @@
from __future__ import annotations
import logging
import os
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def char_replace(name_in):
# Special character hex range:
@ -69,7 +73,7 @@ def convert_to_ascii(input_name, dir_name):
encoded, base2 = char_replace(base)
if encoded:
dir_name = os.path.join(directory, base2)
logger.info(f'Renaming directory to: {base2}.', 'ENCODER')
log.info(f'Renaming directory to: {base2}.')
os.rename(os.path.join(directory, base), dir_name)
if 'NZBOP_SCRIPTDIR' in os.environ:
print(f'[NZB] DIRECTORY={dir_name}')
@ -78,9 +82,7 @@ def convert_to_ascii(input_name, dir_name):
for subdirname in dirnames:
encoded, subdirname2 = char_replace(subdirname)
if encoded:
logger.info(
f'Renaming directory to: {subdirname2}.', 'ENCODER',
)
log.info(f'Renaming directory to: {subdirname2}.')
os.rename(
os.path.join(dirname, subdirname),
os.path.join(dirname, subdirname2),
@ -90,7 +92,7 @@ def convert_to_ascii(input_name, dir_name):
for filename in filenames:
encoded, filename2 = char_replace(filename)
if encoded:
logger.info(f'Renaming file to: {filename2}.', 'ENCODER')
log.info(f'Renaming file to: {filename2}.')
os.rename(
os.path.join(dirname, filename),
os.path.join(dirname, filename2),

64
nzb2media/utils/files.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import re
import shutil
@ -17,11 +18,12 @@ from nzb2media.utils.naming import sanitize_name
from nzb2media.utils.paths import get_dir_size
from nzb2media.utils.paths import make_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def move_file(filename, path, link):
logger.debug(
f'Found file {os.path.split(filename)[1]} in root directory {path}.',
)
log.debug(f'Found file {os.path.split(filename)[1]} in root directory {path}.')
new_path = None
file_ext = os.path.splitext(filename)[1]
try:
@ -46,10 +48,8 @@ def move_file(filename, path, link):
title = os.path.splitext(os.path.basename(filename))[0]
new_path = os.path.join(path, sanitize_name(title))
except Exception as e:
logger.error(
f'Exception parsing name for media file: {os.path.split(filename)[1]}: {e}',
)
except Exception as error:
log.error(f'Exception parsing name for media file: {os.path.split(filename)[1]}: {error}')
if not new_path:
title = os.path.splitext(os.path.basename(filename))[0]
@ -94,9 +94,7 @@ def is_min_size(input_name, min_size):
try:
input_size = get_dir_size(os.path.dirname(input_name))
except Exception:
logger.error(
f'Failed to get file size for {input_name}', 'MINSIZE',
)
log.error(f'Failed to get file size for {input_name}')
return True
# Ignore files under a certain size
@ -170,9 +168,7 @@ def list_media_files(
if delete_ignored == 1:
try:
os.unlink(path)
logger.debug(
f'Ignored file {cur_file} has been removed ...',
)
log.debug(f'Ignored file {cur_file} has been removed ...')
except Exception:
pass
else:
@ -207,9 +203,7 @@ def list_media_files(
if delete_ignored == 1:
try:
os.unlink(full_cur_file)
logger.debug(
f'Ignored file {cur_file} has been removed ...',
)
log.debug(f'Ignored file {cur_file} has been removed ...')
except Exception:
pass
continue
@ -239,7 +233,7 @@ def extract_files(src, dst=None, keep_archive=None):
extracted_folder.append(dir_path)
extracted_archive.append(archive_name)
except Exception:
logger.error(f'Extraction failed for: {full_file_name}')
log.error(f'Extraction failed for: {full_file_name}')
for folder in extracted_folder:
for inputFile in list_media_files(
@ -250,52 +244,34 @@ def extract_files(src, dst=None, keep_archive=None):
archive_name = re.sub(r'part[0-9]+', '', archive_name)
if archive_name not in extracted_archive or keep_archive:
continue # don't remove if we haven't extracted this archive, or if we want to preserve them.
logger.info(
f'Removing extracted archive {full_file_name} from folder {folder} ...',
)
log.info(f'Removing extracted archive {full_file_name} from folder {folder} ...')
try:
if not os.access(inputFile, os.W_OK):
os.chmod(inputFile, stat.S_IWUSR)
os.remove(inputFile)
time.sleep(1)
except Exception as e:
logger.error(f'Unable to remove file {inputFile} due to: {e}')
except Exception as error:
log.error(f'Unable to remove file {inputFile} due to: {error}')
def backup_versioned_file(old_file, version):
num_tries = 0
new_file = f'{old_file}.v{version}'
while not os.path.isfile(new_file):
if not os.path.isfile(old_file):
logger.log(
f'Not creating backup, {old_file} doesn\'t exist', logger.DEBUG,
)
log.debug(f'Not creating backup, {old_file} doesn\'t exist')
break
try:
logger.log(
f'Trying to back up {old_file} to {new_file}',
logger.DEBUG,
)
log.debug(f'Trying to back up {old_file} to {new_file}')
shutil.copy(old_file, new_file)
logger.log('Backup done', logger.DEBUG)
log.debug('Backup done')
break
except Exception as error:
logger.log(
f'Error while trying to back up {old_file} to {new_file} : {error}',
logger.WARNING,
)
log.warning(f'Error while trying to back up {old_file} to {new_file} : {error}')
num_tries += 1
time.sleep(1)
logger.log('Trying again.', logger.DEBUG)
log.debug('Trying again.')
if num_tries >= 10:
logger.log(
f'Unable to back up {old_file} to {new_file} please do it manually.',
logger.ERROR,
)
log.error(f'Unable to back up {old_file} to {new_file} please do it manually.')
return False
return True

104
nzb2media/utils/identification.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import re
@ -8,25 +9,27 @@ import requests
from nzb2media.utils.naming import sanitize_name
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def find_imdbid(dir_name, input_name, omdb_api_key):
imdbid = None
logger.info(f'Attemping imdbID lookup for {input_name}')
log.info(f'Attemping imdbID lookup for {input_name}')
# find imdbid in dirName
logger.info('Searching folder and file names for imdbID ...')
log.info('Searching folder and file names for imdbID ...')
m = re.search(r'\b(tt\d{7,8})\b', dir_name + input_name)
if m:
imdbid = m.group(1)
logger.info(f'Found imdbID [{imdbid}]')
log.info(f'Found imdbID [{imdbid}]')
return imdbid
if os.path.isdir(dir_name):
for file in os.listdir(dir_name):
m = re.search(r'\b(tt\d{7,8})\b', file)
if m:
imdbid = m.group(1)
logger.info(f'Found imdbID [{imdbid}] via file name')
log.info(f'Found imdbID [{imdbid}] via file name')
return imdbid
if 'NZBPR__DNZB_MOREINFO' in os.environ:
dnzb_more_info = os.environ.get('NZBPR__DNZB_MOREINFO', '')
@ -37,9 +40,9 @@ def find_imdbid(dir_name, input_name, omdb_api_key):
m = regex.match(dnzb_more_info)
if m:
imdbid = m.group(1)
logger.info(f'Found imdbID [{imdbid}] from DNZB-MoreInfo')
log.info(f'Found imdbID [{imdbid}] from DNZB-MoreInfo')
return imdbid
logger.info('Searching IMDB for imdbID ...')
log.info('Searching IMDB for imdbID ...')
try:
guess = guessit.guessit(input_name)
except Exception:
@ -58,12 +61,10 @@ def find_imdbid(dir_name, input_name, omdb_api_key):
url = 'http://www.omdbapi.com'
if not omdb_api_key:
logger.info(
'Unable to determine imdbID: No api key provided for omdbapi.com.',
)
log.info('Unable to determine imdbID: No api key provided for omdbapi.com.')
return
logger.debug(f'Opening URL: {url}')
log.debug(f'Opening URL: {url}')
try:
r = requests.get(
@ -73,24 +74,24 @@ def find_imdbid(dir_name, input_name, omdb_api_key):
timeout=(60, 300),
)
except requests.ConnectionError:
logger.error(f'Unable to open URL {url}')
log.error(f'Unable to open URL {url}')
return
try:
results = r.json()
except Exception:
logger.error('No json data returned from omdbapi.com')
log.error('No json data returned from omdbapi.com')
try:
imdbid = results['imdbID']
except Exception:
logger.error('No imdbID returned from omdbapi.com')
log.error('No imdbID returned from omdbapi.com')
if imdbid:
logger.info(f'Found imdbID [{imdbid}]')
log.info(f'Found imdbID [{imdbid}]')
return imdbid
logger.warning(f'Unable to find a imdbID for {input_name}')
log.warning(f'Unable to find a imdbID for {input_name}')
return imdbid
@ -105,78 +106,59 @@ def category_search(
pathlist = os.path.normpath(input_directory).split(os.sep)
if input_category and input_category in pathlist:
logger.debug(
f'SEARCH: Found the Category: {input_category} in directory structure',
)
log.debug(f'SEARCH: Found the Category: {input_category} in directory structure')
elif input_category:
logger.debug(
f'SEARCH: Could not find the category: {input_category} in the directory structure',
)
log.debug(f'SEARCH: Could not find the category: {input_category} in the directory structure')
else:
try:
input_category = list(set(pathlist) & set(categories))[
-1
] # assume last match is most relevant category.
logger.debug(
f'SEARCH: Found Category: {input_category} in directory structure',
)
log.debug(f'SEARCH: Found Category: {input_category} in directory structure')
except IndexError:
input_category = ''
logger.debug(
'SEARCH: Could not find a category in the directory structure',
)
log.debug('SEARCH: Could not find a category in the directory structure')
if not os.path.isdir(input_directory) and os.path.isfile(
input_directory,
): # If the input directory is a file
if not input_name:
input_name = os.path.split(os.path.normpath(input_directory))[1]
return input_directory, input_name, input_category, root
if input_category and os.path.isdir(
os.path.join(input_directory, input_category),
):
logger.info(
f'SEARCH: Found category directory {input_category} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found category directory {input_category} in input directory directory {input_directory}')
input_directory = os.path.join(input_directory, input_category)
logger.info(f'SEARCH: Setting input_directory to {input_directory}')
log.info(f'SEARCH: Setting input_directory to {input_directory}')
if input_name and os.path.isdir(os.path.join(input_directory, input_name)):
logger.info(
f'SEARCH: Found torrent directory {input_name} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found torrent directory {input_name} in input directory directory {input_directory}')
input_directory = os.path.join(input_directory, input_name)
logger.info(f'SEARCH: Setting input_directory to {input_directory}')
log.info(f'SEARCH: Setting input_directory to {input_directory}')
tordir = True
elif input_name and os.path.isdir(
os.path.join(input_directory, sanitize_name(input_name)),
):
logger.info(
f'SEARCH: Found torrent directory {sanitize_name(input_name)} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found torrent directory {sanitize_name(input_name)} in input directory directory {input_directory}')
input_directory = os.path.join(
input_directory, sanitize_name(input_name),
)
logger.info(f'SEARCH: Setting input_directory to {input_directory}')
log.info(f'SEARCH: Setting input_directory to {input_directory}')
tordir = True
elif input_name and os.path.isfile(
os.path.join(input_directory, input_name),
):
logger.info(
f'SEARCH: Found torrent file {input_name} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found torrent file {input_name} in input directory directory {input_directory}')
input_directory = os.path.join(input_directory, input_name)
logger.info(f'SEARCH: Setting input_directory to {input_directory}')
log.info(f'SEARCH: Setting input_directory to {input_directory}')
tordir = True
elif input_name and os.path.isfile(
os.path.join(input_directory, sanitize_name(input_name)),
):
logger.info(
f'SEARCH: Found torrent file {sanitize_name(input_name)} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found torrent file {sanitize_name(input_name)} in input directory directory {input_directory}')
input_directory = os.path.join(
input_directory, sanitize_name(input_name),
)
logger.info(f'SEARCH: Setting input_directory to {input_directory}')
log.info(f'SEARCH: Setting input_directory to {input_directory}')
tordir = True
elif input_name and os.path.isdir(input_directory):
for file in os.listdir(input_directory):
@ -184,13 +166,9 @@ def category_search(
input_name,
sanitize_name(input_name),
]:
logger.info(
f'SEARCH: Found torrent file {file} in input directory directory {input_directory}',
)
log.info(f'SEARCH: Found torrent file {file} in input directory directory {input_directory}')
input_directory = os.path.join(input_directory, file)
logger.info(
f'SEARCH: Setting input_directory to {input_directory}',
)
log.info(f'SEARCH: Setting input_directory to {input_directory}')
input_name = file
tordir = True
break
@ -209,9 +187,7 @@ def category_search(
index = pathlist.index(input_category)
if index + 1 < len(pathlist):
tordir = True
logger.info(
f'SEARCH: Found a unique directory {pathlist[index + 1]} in the category directory',
)
log.info(f'SEARCH: Found a unique directory {pathlist[index + 1]} in the category directory')
if not input_name:
input_name = pathlist[index + 1]
except ValueError:
@ -219,9 +195,7 @@ def category_search(
if input_name and not tordir:
if input_name in pathlist or sanitize_name(input_name) in pathlist:
logger.info(
f'SEARCH: Found torrent directory {input_name} in the directory structure',
)
log.info(f'SEARCH: Found torrent directory {input_name} in the directory structure')
tordir = True
else:
root = 1
@ -229,11 +203,7 @@ def category_search(
root = 2
if root > 0:
logger.info(
'SEARCH: Could not find a unique directory for this download. Assume a common directory.',
)
logger.info(
'SEARCH: We will try and determine which files to process, individually',
)
log.info('SEARCH: Could not find a unique directory for this download. Assume a common directory.')
log.info('SEARCH: We will try and determine which files to process, individually')
return input_directory, input_name, input_category, root

63
nzb2media/utils/links.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import shutil
@ -7,6 +8,9 @@ import linktastic
from nzb2media.utils.paths import make_dir
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
try:
from jaraco.windows.filesystem import islink, readlink
except ImportError:
@ -18,73 +22,55 @@ except ImportError:
def copy_link(src, target_link, use_link):
logger.info(f'MEDIAFILE: [{os.path.basename(target_link)}]', 'COPYLINK')
logger.info(f'SOURCE FOLDER: [{os.path.dirname(src)}]', 'COPYLINK')
logger.info(f'TARGET FOLDER: [{os.path.dirname(target_link)}]', 'COPYLINK')
log.info(f'MEDIAFILE: [{os.path.basename(target_link)}]')
log.info(f'SOURCE FOLDER: [{os.path.dirname(src)}]')
log.info(f'TARGET FOLDER: [{os.path.dirname(target_link)}]')
if src != target_link and os.path.exists(target_link):
logger.info(
'MEDIAFILE already exists in the TARGET folder, skipping ...',
'COPYLINK',
)
log.info('MEDIAFILE already exists in the TARGET folder, skipping ...')
return True
elif (
src == target_link
and os.path.isfile(target_link)
and os.path.isfile(src)
):
logger.info(
'SOURCE AND TARGET files are the same, skipping ...', 'COPYLINK',
)
log.info('SOURCE AND TARGET files are the same, skipping ...')
return True
elif src == os.path.dirname(target_link):
logger.info(
'SOURCE AND TARGET folders are the same, skipping ...', 'COPYLINK',
)
log.info('SOURCE AND TARGET folders are the same, skipping ...')
return True
make_dir(os.path.dirname(target_link))
try:
if use_link == 'dir':
logger.info(
'Directory linking SOURCE FOLDER -> TARGET FOLDER', 'COPYLINK',
)
log.info('Directory linking SOURCE FOLDER -> TARGET FOLDER')
linktastic.dirlink(src, target_link)
return True
if use_link == 'junction':
logger.info(
'Directory junction linking SOURCE FOLDER -> TARGET FOLDER',
'COPYLINK',
)
log.info('Directory junction linking SOURCE FOLDER -> TARGET FOLDER')
linktastic.dirlink(src, target_link)
return True
elif use_link == 'hard':
logger.info(
'Hard linking SOURCE MEDIAFILE -> TARGET FOLDER', 'COPYLINK',
)
log.info('Hard linking SOURCE MEDIAFILE -> TARGET FOLDER')
linktastic.link(src, target_link)
return True
elif use_link == 'sym':
logger.info(
'Sym linking SOURCE MEDIAFILE -> TARGET FOLDER', 'COPYLINK',
)
log.info('Sym linking SOURCE MEDIAFILE -> TARGET FOLDER')
linktastic.symlink(src, target_link)
return True
elif use_link == 'move-sym':
logger.info(
'Sym linking SOURCE MEDIAFILE -> TARGET FOLDER', 'COPYLINK',
)
log.info('Sym linking SOURCE MEDIAFILE -> TARGET FOLDER')
shutil.move(src, target_link)
linktastic.symlink(target_link, src)
return True
elif use_link == 'move':
logger.info('Moving SOURCE MEDIAFILE -> TARGET FOLDER', 'COPYLINK')
log.info('Moving SOURCE MEDIAFILE -> TARGET FOLDER')
shutil.move(src, target_link)
return True
except Exception as e:
logger.warning(f'Error: {e}, copying instead ... ', 'COPYLINK')
except Exception as error:
log.warning(f'Error: {error}, copying instead ... ')
logger.info('Copying SOURCE MEDIAFILE -> TARGET FOLDER', 'COPYLINK')
log.info('Copying SOURCE MEDIAFILE -> TARGET FOLDER')
shutil.copy(src, target_link)
return True
@ -101,17 +87,12 @@ def replace_links(link, max_depth=10):
link_depth = attempt
if not link_depth:
logger.debug(f'{link} is not a link')
log.debug(f'{link} is not a link')
elif link_depth > max_depth or (
link_depth == max_depth and islink(target)
):
logger.warning(
f'Exceeded maximum depth {max_depth} while following link {link}',
)
log.warning(f'Exceeded maximum depth {max_depth} while following link {link}')
else:
logger.info(
f'Changing sym-link: {link} to point directly to file: {target}',
'COPYLINK',
)
log.info(f'Changing sym-link: {link} to point directly to file: {target}')
os.unlink(link)
linktastic.symlink(target, link)

26
nzb2media/utils/network.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import socket
import struct
import time
@ -8,6 +9,9 @@ import requests
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def make_wake_on_lan_packet(mac_address):
"""Build the Wake-On-LAN 'Magic Packet'."""
@ -28,7 +32,7 @@ def wake_on_lan(ethernet_address):
connection.setsockopt(socket.SOL_SOCKET, socket.SO_BROADCAST, 1)
connection.sendto(magic_packet, ('<broadcast>', 9))
logger.info(f'WakeOnLan sent for mac: {ethernet_address}')
log.info(f'WakeOnLan sent for mac: {ethernet_address}')
def test_connection(host, port):
@ -49,37 +53,37 @@ def wake_up():
mac = wol['mac']
max_attempts = 4
logger.info('Trying to wake On lan.')
log.info('Trying to wake On lan.')
for attempt in range(0, max_attempts):
logger.info(f'Attempt {attempt + 1} of {max_attempts}')
log.info(f'Attempt {attempt + 1} of {max_attempts}')
if test_connection(host, port) == 'Up':
logger.info(f'System with mac: {mac} has been woken.')
log.info(f'System with mac: {mac} has been woken.')
break
wake_on_lan(mac)
time.sleep(20)
else:
if test_connection(host, port) == 'Down': # final check.
msg = 'System with mac: {0} has not woken after {1} attempts.'
logger.warning(msg.format(mac, max_attempts))
log.warning(msg.format(mac, max_attempts))
logger.info('Continuing with the rest of the script.')
log.info('Continuing with the rest of the script.')
def server_responding(base_url):
logger.debug(f'Attempting to connect to server at {base_url}', 'SERVER')
log.debug(f'Attempting to connect to server at {base_url}')
try:
requests.get(base_url, timeout=(60, 120), verify=False)
except (requests.ConnectionError, requests.exceptions.Timeout):
logger.error(f'Server failed to respond at {base_url}', 'SERVER')
log.error(f'Server failed to respond at {base_url}')
return False
else:
logger.debug(f'Server responded at {base_url}', 'SERVER')
log.debug(f'Server responded at {base_url}')
return True
def find_download(client_agent, download_id):
logger.debug(f'Searching for Download on {client_agent} ...')
log.debug(f'Searching for Download on {client_agent} ...')
if client_agent == 'utorrent':
torrents = nzb2media.TORRENT_CLASS.list()[1]['torrents']
for torrent in torrents:
@ -115,7 +119,7 @@ def find_download(client_agent, download_id):
url, params=params, verify=False, timeout=(30, 120),
)
except requests.ConnectionError:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return False # failure
result = r.json()

24
nzb2media/utils/nzb.py
View file

@ -1,16 +1,20 @@
from __future__ import annotations
import logging
import os
import requests
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def get_nzoid(input_name):
nzoid = None
slots = []
logger.debug('Searching for nzoid from SAbnzbd ...')
log.debug('Searching for nzoid from SAbnzbd ...')
if 'http' in nzb2media.SABNZBD_HOST:
base_url = f'{nzb2media.SABNZBD_HOST}:{nzb2media.SABNZBD_PORT}/api'
else:
@ -24,7 +28,7 @@ def get_nzoid(input_name):
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 120))
except requests.ConnectionError:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return nzoid # failure
try:
result = r.json()
@ -36,12 +40,12 @@ def get_nzoid(input_name):
],
)
except Exception:
logger.warning('Data from SABnzbd queue could not be parsed')
log.warning('Data from SABnzbd queue could not be parsed')
params['mode'] = 'history'
try:
r = requests.get(url, params=params, verify=False, timeout=(30, 120))
except requests.ConnectionError:
logger.error('Unable to open URL')
log.error('Unable to open URL')
return nzoid # failure
try:
result = r.json()
@ -53,21 +57,21 @@ def get_nzoid(input_name):
],
)
except Exception:
logger.warning('Data from SABnzbd history could not be parsed')
log.warning('Data from SABnzbd history could not be parsed')
try:
for nzo_id, name in slots:
if name in [input_name, clean_name]:
nzoid = nzo_id
logger.debug(f'Found nzoid: {nzoid}')
log.debug(f'Found nzoid: {nzoid}')
break
except Exception:
logger.warning('Data from SABnzbd could not be parsed')
log.warning('Data from SABnzbd could not be parsed')
return nzoid
def report_nzb(failure_link, client_agent):
# Contact indexer site
logger.info('Sending failure notification to indexer site')
log.info('Sending failure notification to indexer site')
if client_agent == 'nzbget':
headers = {'User-Agent': 'NZBGet / nzbToMedia.py'}
elif client_agent == 'sabnzbd':
@ -76,6 +80,6 @@ def report_nzb(failure_link, client_agent):
return
try:
requests.post(failure_link, headers=headers, timeout=(30, 300))
except Exception as e:
logger.error(f'Unable to open URL {failure_link} due to {e}')
except Exception as error:
log.error(f'Unable to open URL {failure_link} due to {error}')
return

8
nzb2media/utils/parsers.py
View file

@ -1,9 +1,13 @@
from __future__ import annotations
import logging
import os
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def parse_other(args):
return os.path.normpath(args[1]), '', '', '', ''
@ -99,7 +103,7 @@ def parse_synods(args):
input_id = f'dbid_{torrent_id}'
# res = nzb2media.TORRENT_CLASS.tasks_list(additional_param='detail')
res = nzb2media.TORRENT_CLASS.tasks_info(input_id, additional_param='detail')
logger.debug(f'result from syno {res}')
log.debug(f'result from syno {res}')
if res['success']:
try:
tasks = res['data']['tasks']
@ -107,7 +111,7 @@ def parse_synods(args):
input_id = task['id']
input_directory = task['additional']['detail']['destination']
except:
logger.error('unable to find download details in Synology DS')
log.error('unable to find download details in Synology DS')
# Syno paths appear to be relative. Let's test to see if the returned path exists, and if not append to /volume1/
if not os.path.isdir(input_directory):
for root in ['/volume1/', '/volume2/', '/volume3/', '/volume4/']:

47
nzb2media/utils/paths.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import re
import shutil
@ -8,6 +9,9 @@ from functools import partial
import nzb2media
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def onerror(func, path, exc_info):
"""
@ -29,11 +33,11 @@ def onerror(func, path, exc_info):
def remove_dir(dir_name):
logger.info(f'Deleting {dir_name}')
log.info(f'Deleting {dir_name}')
try:
shutil.rmtree(dir_name, onerror=onerror)
except Exception:
logger.error(f'Unable to delete folder {dir_name}')
log.error(f'Unable to delete folder {dir_name}')
def make_dir(path):
@ -77,7 +81,7 @@ def remove_empty_folders(path, remove_root=True):
return
# remove empty subfolders
logger.debug(f'Checking for empty folders in:{path}')
log.debug(f'Checking for empty folders in:{path}')
files = os.listdir(path)
if len(files):
for f in files:
@ -88,7 +92,7 @@ def remove_empty_folders(path, remove_root=True):
# if folder empty, delete it
files = os.listdir(path)
if len(files) == 0 and remove_root:
logger.debug(f'Removing empty folder:{path}')
log.debug(f'Removing empty folder:{path}')
os.rmdir(path)
@ -98,66 +102,51 @@ def remove_read_only(filename):
file_attribute = os.stat(filename)[0]
if not file_attribute & stat.S_IWRITE:
# File is read-only, so make it writeable
logger.debug(
f'Read only mode on file {filename}. Attempting to make it writeable',
)
log.debug(f'Read only mode on file {filename}. Attempting to make it writeable')
try:
os.chmod(filename, stat.S_IWRITE)
except Exception:
logger.warning(
f'Cannot change permissions of {filename}', logger.WARNING,
)
log.warning(f'Cannot change permissions of {filename}')
def flatten_dir(destination, files):
logger.info(f'FLATTEN: Flattening directory: {destination}')
log.info(f'FLATTEN: Flattening directory: {destination}')
for outputFile in files:
dir_path = os.path.dirname(outputFile)
file_name = os.path.basename(outputFile)
if dir_path == destination:
continue
target = os.path.join(destination, file_name)
try:
shutil.move(outputFile, target)
except Exception:
logger.error(f'Could not flatten {outputFile}', 'FLATTEN')
log.error(f'Could not flatten {outputFile}')
remove_empty_folders(destination) # Cleanup empty directories
def clean_directory(path, files):
if not os.path.exists(path):
logger.info(
f'Directory {path} has been processed and removed ...', 'CLEANDIR',
)
log.info(f'Directory {path} has been processed and removed ...')
return
if nzb2media.FORCE_CLEAN and not nzb2media.FAILED:
logger.info(f'Doing Forceful Clean of {path}', 'CLEANDIR')
log.info(f'Doing Forceful Clean of {path}')
remove_dir(path)
return
if files:
logger.info(
f'Directory {path} still contains {len(files)} unprocessed file(s), skipping ...',
'CLEANDIRS',
)
log.info(f'Directory {path} still contains {len(files)} unprocessed file(s), skipping ...')
return
logger.info(
f'Directory {path} has been processed, removing ...', 'CLEANDIRS',
)
log.info(f'Directory {path} has been processed, removing ...')
try:
shutil.rmtree(path, onerror=onerror)
except Exception:
logger.error(f'Unable to delete directory {path}')
log.error(f'Unable to delete directory {path}')
def rchmod(path, mod):
logger.log(f'Changing file mode of {path} to {oct(mod)}')
log.info(f'Changing file mode of {path} to {oct(mod)}')
os.chmod(path, mod)
if not os.path.isdir(path):
return # Skip files

7
nzb2media/utils/processes.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import os
import socket
import subprocess
@ -16,6 +17,9 @@ if os.name == 'nt':
from win32api import CloseHandle, GetLastError
from winerror import ERROR_ALREADY_EXISTS
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class WindowsProcess:
def __init__(self):
@ -109,8 +113,7 @@ def restart():
if popen_list:
popen_list += SYS_ARGV
logger.log(f'Restarting nzbToMedia with {popen_list}')
logger.close()
log.info(f'Restarting nzbToMedia with {popen_list}')
p = subprocess.Popen(popen_list, cwd=os.getcwd())
p.wait()
status = p.returncode

24
nzb2media/utils/torrent.py
View file

@ -1,5 +1,6 @@
from __future__ import annotations
import logging
import time
import nzb2media
@ -9,6 +10,9 @@ from nzb2media.torrent import synology
from nzb2media.torrent import transmission
from nzb2media.torrent import utorrent
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
torrent_clients = {
'deluge': deluge,
'qbittorrent': qbittorrent,
@ -31,9 +35,7 @@ def create_torrent_class(client_agent):
def pause_torrent(client_agent, input_hash, input_id, input_name):
logger.debug(
f'Stopping torrent {input_name} in {client_agent} while processing',
)
log.debug(f'Stopping torrent {input_name} in {client_agent} while processing')
try:
if client_agent == 'utorrent' and nzb2media.TORRENT_CLASS != '':
nzb2media.TORRENT_CLASS.stop(input_hash)
@ -47,15 +49,13 @@ def pause_torrent(client_agent, input_hash, input_id, input_name):
nzb2media.TORRENT_CLASS.pause(input_hash)
time.sleep(5)
except Exception:
logger.warning(
f'Failed to stop torrent {input_name} in {client_agent}',
)
log.warning(f'Failed to stop torrent {input_name} in {client_agent}')
def resume_torrent(client_agent, input_hash, input_id, input_name):
if not nzb2media.TORRENT_RESUME == 1:
return
logger.debug(f'Starting torrent {input_name} in {client_agent}')
log.debug(f'Starting torrent {input_name} in {client_agent}')
try:
if client_agent == 'utorrent' and nzb2media.TORRENT_CLASS != '':
nzb2media.TORRENT_CLASS.start(input_hash)
@ -69,14 +69,12 @@ def resume_torrent(client_agent, input_hash, input_id, input_name):
nzb2media.TORRENT_CLASS.resume(input_hash)
time.sleep(5)
except Exception:
logger.warning(
f'Failed to start torrent {input_name} in {client_agent}',
)
log.warning(f'Failed to start torrent {input_name} in {client_agent}')
def remove_torrent(client_agent, input_hash, input_id, input_name):
if nzb2media.DELETE_ORIGINAL == 1 or nzb2media.USE_LINK == 'move':
logger.debug(f'Deleting torrent {input_name} from {client_agent}')
log.debug(f'Deleting torrent {input_name} from {client_agent}')
try:
if client_agent == 'utorrent' and nzb2media.TORRENT_CLASS != '':
nzb2media.TORRENT_CLASS.removedata(input_hash)
@ -91,8 +89,6 @@ def remove_torrent(client_agent, input_hash, input_id, input_name):
nzb2media.TORRENT_CLASS.delete_permanently(input_hash)
time.sleep(5)
except Exception:
logger.warning(
f'Failed to delete torrent {input_name} in {client_agent}',
)
log.warning(f'Failed to delete torrent {input_name} in {client_agent}')
else:
resume_torrent(client_agent, input_hash, input_id, input_name)

236
nzb2media/version_check.py
View file

@ -2,6 +2,7 @@
# Modified by: echel0n
from __future__ import annotations
import logging
import os
import platform
import re
@ -15,6 +16,9 @@ from urllib.request import urlretrieve
import nzb2media
from nzb2media import github_api as github
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
class CheckVersion:
"""Version checker that runs in a thread with the SB scheduler."""
@ -60,15 +64,13 @@ class CheckVersion:
force: if true the VERSION_NOTIFY setting will be ignored and a check will be forced
"""
if not nzb2media.VERSION_NOTIFY and not force:
logger.log(
'Version checking is disabled, not checking for the newest version',
)
log.info('Version checking is disabled, not checking for the newest version')
return False
logger.log(f'Checking if {self.install_type} needs an update')
log.info(f'Checking if {self.install_type} needs an update')
if not self.updater.need_update():
nzb2media.NEWEST_VERSION_STRING = None
logger.log('No update needed')
log.info('No update needed')
return False
self.updater.set_newest_text()
@ -104,9 +106,7 @@ class GitUpdateManager(UpdateManager):
self._num_commits_ahead = 0
def _git_error(self):
logger.debug(
'Unable to find your git executable - Set git_path in your autoProcessMedia.cfg OR delete your .git folder and run from source to enable updates.',
)
log.debug('Unable to find your git executable - Set git_path in your autoProcessMedia.cfg OR delete your .git folder and run from source to enable updates.')
def _find_working_git(self):
test_cmd = 'version'
@ -116,19 +116,14 @@ class GitUpdateManager(UpdateManager):
else:
main_git = 'git'
logger.log(
'Checking if we can use git commands: {git} {cmd}'.format(
git=main_git, cmd=test_cmd,
),
logger.DEBUG,
)
log.debug('Checking if we can use git commands: {git} {cmd}'.format(git=main_git, cmd=test_cmd))
output, err, exit_status = self._run_git(main_git, test_cmd)
if exit_status == 0:
logger.log(f'Using: {main_git}', logger.DEBUG)
log.debug(f'Using: {main_git}')
return main_git
else:
logger.log(f'Not using: {main_git}', logger.DEBUG)
log.debug(f'Not using: {main_git}')
# trying alternatives
@ -143,25 +138,20 @@ class GitUpdateManager(UpdateManager):
alternative_git.append(main_git.lower())
if alternative_git:
logger.log('Trying known alternative git locations', logger.DEBUG)
log.debug('Trying known alternative git locations')
for cur_git in alternative_git:
logger.log(
'Checking if we can use git commands: {git} {cmd}'.format(
git=cur_git, cmd=test_cmd,
),
logger.DEBUG,
)
log.debug('Checking if we can use git commands: {git} {cmd}'.format(git=cur_git, cmd=test_cmd))
output, err, exit_status = self._run_git(cur_git, test_cmd)
if exit_status == 0:
logger.log(f'Using: {cur_git}', logger.DEBUG)
log.debug(f'Using: {cur_git}')
return cur_git
else:
logger.log(f'Not using: {cur_git}', logger.DEBUG)
log.debug(f'Not using: {cur_git}')
# Still haven't found a working git
logger.debug(
log.debug(
'Unable to find your git executable - '
'Set git_path in your autoProcessMedia.cfg OR '
'delete your .git folder and run from source to enable updates.',
@ -175,21 +165,14 @@ class GitUpdateManager(UpdateManager):
err = None
if not git_path:
logger.log(
'No git specified, can\'t use git commands', logger.DEBUG,
)
log.debug('No git specified, can\'t use git commands')
exit_status = 1
return output, err, exit_status
cmd = f'{git_path} {args}'
try:
logger.log(
'Executing {cmd} with your shell in {directory}'.format(
cmd=cmd, directory=nzb2media.APP_ROOT,
),
logger.DEBUG,
)
log.debug('Executing {cmd} with your shell in {directory}'.format(cmd=cmd, directory=nzb2media.APP_ROOT))
p = subprocess.Popen(
cmd,
stdin=subprocess.PIPE,
@ -206,29 +189,21 @@ class GitUpdateManager(UpdateManager):
if output:
output = output.strip()
if nzb2media.LOG_GIT:
logger.log(f'git output: {output}', logger.DEBUG)
log.debug(f'git output: {output}')
except OSError:
logger.log(f'Command {cmd} didn\'t work')
log.error(f'Command {cmd} didn\'t work')
exit_status = 1
exit_status = 128 if ('fatal:' in output) or err else exit_status
if exit_status == 0:
logger.log(f'{cmd} : returned successful', logger.DEBUG)
log.debug(f'{cmd} : returned successful')
exit_status = 0
elif nzb2media.LOG_GIT and exit_status in (1, 128):
logger.log(
f'{cmd} returned : {output}',
logger.DEBUG,
)
log.debug(f'{cmd} returned : {output}')
else:
if nzb2media.LOG_GIT:
logger.log(
'{cmd} returned : {output}, treat as error for now'.format(
cmd=cmd, output=output,
),
logger.DEBUG,
)
log.debug('{cmd} returned : {output}, treat as error for now'.format(cmd=cmd, output=output))
exit_status = 1
return output, err, exit_status
@ -248,10 +223,7 @@ class GitUpdateManager(UpdateManager):
if exit_status == 0 and output:
cur_commit_hash = output.strip()
if not re.match('^[a-z0-9]+$', cur_commit_hash):
logger.log(
'Output doesn\'t look like a hash, not using it',
logger.ERROR,
)
log.error('Output doesn\'t look like a hash, not using it')
return False
self._cur_commit_hash = cur_commit_hash
if self._cur_commit_hash:
@ -290,10 +262,7 @@ class GitUpdateManager(UpdateManager):
)
if not exit_status == 0:
logger.log(
'Unable to contact github, can\'t check for update',
logger.ERROR,
)
log.error('Unable to contact github, can\'t check for update')
return
# get latest commit_hash from remote
@ -305,16 +274,12 @@ class GitUpdateManager(UpdateManager):
cur_commit_hash = output.strip()
if not re.match('^[a-z0-9]+$', cur_commit_hash):
logger.log(
'Output doesn\'t look like a hash, not using it',
logger.DEBUG,
)
log.debug('Output doesn\'t look like a hash, not using it')
return
else:
self._newest_commit_hash = cur_commit_hash
else:
logger.log('git didn\'t return newest commit hash', logger.DEBUG)
log.debug('git didn\'t return newest commit hash')
return
# get number of commits behind and ahead (option --count not supported git < 1.7.2)
@ -329,47 +294,22 @@ class GitUpdateManager(UpdateManager):
self._num_commits_ahead = int(output.count('>'))
except Exception:
logger.log(
'git didn\'t return numbers for behind and ahead, not using it',
logger.DEBUG,
)
log.debug('git didn\'t return numbers for behind and ahead, not using it')
return
logger.log(
'cur_commit = {current} % (newest_commit)= {new}, '
'num_commits_behind = {x}, num_commits_ahead = {y}'.format(
current=self._cur_commit_hash,
new=self._newest_commit_hash,
x=self._num_commits_behind,
y=self._num_commits_ahead,
),
logger.DEBUG,
)
log.debug('cur_commit = {current} % (newest_commit)= {new}, num_commits_behind = {x}, num_commits_ahead = {y}'.format(current=self._cur_commit_hash, new=self._newest_commit_hash, x=self._num_commits_behind, y=self._num_commits_ahead))
def set_newest_text(self):
if self._num_commits_ahead:
logger.log(
'Local branch is ahead of {branch}. Automatic update not possible.'.format(
branch=self.branch,
),
logger.ERROR,
)
log.error('Local branch is ahead of {branch}. Automatic update not possible.'.format(branch=self.branch))
elif self._num_commits_behind:
logger.log(
'There is a newer version available (you\'re {x} commit{s} behind)'.format(
x=self._num_commits_behind,
s='s' if self._num_commits_behind > 1 else '',
),
logger.MESSAGE,
)
log.info('There is a newer version available (you\'re {x} commit{s} behind)'.format(x=self._num_commits_behind, s='s' if self._num_commits_behind > 1 else ''))
else:
return
def need_update(self):
if not self._find_installed_version():
logger.error(
'Unable to determine installed version via git, please check your logs!',
)
log.error('Unable to determine installed version via git, please check your logs!')
return False
if not self._cur_commit_hash:
@ -378,10 +318,7 @@ class GitUpdateManager(UpdateManager):
try:
self._check_github_for_update()
except Exception as error:
logger.log(
f'Unable to contact github, can\'t check for update: {error!r}',
logger.ERROR,
)
log.error(f'Unable to contact github, can\'t check for update: {error!r}')
return False
if self._num_commits_behind > 0:
@ -428,9 +365,7 @@ class SourceUpdateManager(UpdateManager):
with open(version_file) as fp:
self._cur_commit_hash = fp.read().strip(' \n\r')
except OSError as error:
logger.log(
f'Unable to open \'version.txt\': {error}', logger.DEBUG,
)
log.debug(f'Unable to open \'version.txt\': {error}')
if not self._cur_commit_hash:
self._cur_commit_hash = None
@ -444,10 +379,7 @@ class SourceUpdateManager(UpdateManager):
try:
self._check_github_for_update()
except Exception as error:
logger.log(
f'Unable to contact github, can\'t check for update: {error!r}',
logger.ERROR,
)
log.error(f'Unable to contact github, can\'t check for update: {error!r}')
return False
if not self._cur_commit_hash or self._num_commits_behind > 0:
@ -472,7 +404,8 @@ class SourceUpdateManager(UpdateManager):
self.github_repo_user, self.github_repo, self.branch,
)
# try to get newest commit hash and commits behind directly by comparing branch and current commit
# try to get newest commit hash and commits behind directly by
# comparing branch and current commit
if self._cur_commit_hash:
branch_compared = gh.compare(
base=self.branch, head=self._cur_commit_hash,
@ -501,14 +434,7 @@ class SourceUpdateManager(UpdateManager):
# when _cur_commit_hash doesn't match anything _num_commits_behind == 100
self._num_commits_behind += 1
logger.log(
'cur_commit = {current} % (newest_commit)= {new}, num_commits_behind = {x}'.format(
current=self._cur_commit_hash,
new=self._newest_commit_hash,
x=self._num_commits_behind,
),
logger.DEBUG,
)
log.debug('cur_commit = {current} % (newest_commit)= {new}, num_commits_behind = {x}'.format(current=self._cur_commit_hash, new=self._newest_commit_hash, x=self._num_commits_behind))
def set_newest_text(self):
@ -516,29 +442,16 @@ class SourceUpdateManager(UpdateManager):
nzb2media.NEWEST_VERSION_STRING = None
if not self._cur_commit_hash:
logger.log(
'Unknown current version number, don\'t know if we should update or not',
logger.ERROR,
)
log.error('Unknown current version number, don\'t know if we should update or not')
elif self._num_commits_behind > 0:
logger.log(
'There is a newer version available (you\'re {x} commit{s} behind)'.format(
x=self._num_commits_behind,
s='s' if self._num_commits_behind > 1 else '',
),
logger.MESSAGE,
)
log.info('There is a newer version available (you\'re {x} commit{s} behind)'.format(x=self._num_commits_behind, s='s' if self._num_commits_behind > 1 else ''))
else:
return
def update(self):
"""Download and install latest source tarball from github."""
tar_download_url = (
'https://github.com/{org}/{repo}/tarball/{branch}'.format(
org=self.github_repo_user,
repo=self.github_repo,
branch=self.branch,
)
'https://github.com/{org}/{repo}/tarball/{branch}'.format(org=self.github_repo_user, repo=self.github_repo, branch=self.branch)
)
version_path = os.path.join(nzb2media.APP_ROOT, 'version.txt')
@ -547,49 +460,35 @@ class SourceUpdateManager(UpdateManager):
sb_update_dir = os.path.join(nzb2media.APP_ROOT, 'sb-update')
if os.path.isdir(sb_update_dir):
logger.log(
f'Clearing out update folder {sb_update_dir} before extracting',
)
log.info(f'Clearing out update folder {sb_update_dir} before extracting')
shutil.rmtree(sb_update_dir)
logger.log(
f'Creating update folder {sb_update_dir} before extracting',
)
log.info(f'Creating update folder {sb_update_dir} before extracting')
os.makedirs(sb_update_dir)
# retrieve file
logger.log(f'Downloading update from {tar_download_url!r}')
log.info(f'Downloading update from {tar_download_url!r}')
tar_download_path = os.path.join(
sb_update_dir, 'nzbtomedia-update.tar',
)
urlretrieve(tar_download_url, tar_download_path)
if not os.path.isfile(tar_download_path):
logger.log(
'Unable to retrieve new version from {url}, can\'t update'.format(
url=tar_download_url,
),
logger.ERROR,
)
log.error('Unable to retrieve new version from {url}, can\'t update'.format(url=tar_download_url))
return False
if not tarfile.is_tarfile(tar_download_path):
logger.log(
'Retrieved version from {url} is corrupt, can\'t update'.format(
url=tar_download_url,
),
logger.ERROR,
)
log.error('Retrieved version from {url} is corrupt, can\'t update'.format(url=tar_download_url))
return False
# extract to sb-update dir
logger.log(f'Extracting file {tar_download_path}')
log.info(f'Extracting file {tar_download_path}')
tar = tarfile.open(tar_download_path)
tar.extractall(sb_update_dir)
tar.close()
# delete .tar.gz
logger.log(f'Deleting file {tar_download_path}')
log.info(f'Deleting file {tar_download_path}')
os.remove(tar_download_path)
# find update dir name
@ -599,23 +498,16 @@ class SourceUpdateManager(UpdateManager):
if os.path.isdir(os.path.join(sb_update_dir, x))
]
if len(update_dir_contents) != 1:
logger.log(
f'Invalid update data, update failed: {update_dir_contents}',
logger.ERROR,
)
log.error(f'Invalid update data, update failed: {update_dir_contents}')
return False
content_dir = os.path.join(sb_update_dir, update_dir_contents[0])
# walk temp folder and move files to main folder
logger.log(
'Moving files from {source} to {destination}'.format(
source=content_dir, destination=nzb2media.APP_ROOT,
),
)
log.info('Moving files from {source} to {destination}'.format(source=content_dir, destination=nzb2media.APP_ROOT))
for dirname, _, filenames in os.walk(
content_dir,
): # @UnusedVariable
dirname = dirname[len(content_dir) + 1 :]
dirname = dirname[len(content_dir) + 1:]
for curfile in filenames:
old_path = os.path.join(content_dir, dirname, curfile)
new_path = os.path.join(nzb2media.APP_ROOT, dirname, curfile)
@ -629,15 +521,9 @@ class SourceUpdateManager(UpdateManager):
os.remove(new_path)
os.renames(old_path, new_path)
except Exception as error:
logger.log(
'Unable to update {path}: {msg}'.format(
path=new_path, msg=error,
),
logger.DEBUG,
)
os.remove(
old_path,
) # Trash the updated file without moving in new path
log.debug('Unable to update {path}: {msg}'.format(path=new_path, msg=error))
# Trash the updated file without moving in new path
os.remove(old_path)
continue
if os.path.isfile(new_path):
@ -649,20 +535,12 @@ class SourceUpdateManager(UpdateManager):
with open(version_path, 'w') as ver_file:
ver_file.write(self._newest_commit_hash)
except OSError as error:
logger.log(
'Unable to write version file, update not complete: {msg}'.format(
msg=error,
),
logger.ERROR,
)
log.error('Unable to write version file, update not complete: {msg}'.format(msg=error),)
return False
except Exception as error:
logger.log(
f'Error while trying to update: {error}',
logger.ERROR,
)
logger.log(f'Traceback: {traceback.format_exc()}', logger.DEBUG)
log.error(f'Error while trying to update: {error}')
log.debug(f'Traceback: {traceback.format_exc()}')
return False
return True

20
nzbToMedia.py
View file

@ -1,3 +1,4 @@
import logging
import os
import sys
@ -6,17 +7,20 @@ from nzb2media.processor import nzbget, sab, manual
from nzb2media.processor.nzb import process
from nzb2media.auto_process.common import ProcessResult
log = logging.getLogger(__name__)
log.addHandler(logging.NullHandler())
def main(args, section=None):
# Initialize the config
nzb2media.initialize(section)
logger.info('#########################################################')
logger.info(f'## ..::[{os.path.basename(__file__)}]::.. ##')
logger.info('#########################################################')
log.info('#########################################################')
log.info(f'## ..::[{os.path.basename(__file__)}]::.. ##')
log.info('#########################################################')
# debug command line options
logger.debug(f'Options passed into nzbToMedia: {args}')
log.debug(f'Options passed into nzbToMedia: {args}')
# Post-Processing Result
result = ProcessResult(
@ -35,22 +39,22 @@ def main(args, section=None):
result = sab.process(args)
# Generic program
elif len(args) > 5 and args[5] == 'generic':
logger.info('Script triggered from generic program')
log.info('Script triggered from generic program')
result = process(args[1], input_name=args[2], input_category=args[3], download_id=args[4])
elif nzb2media.NZB_NO_MANUAL:
logger.warning('Invalid number of arguments received from client, and no_manual set')
log.warning('Invalid number of arguments received from client, and no_manual set')
else:
manual.process()
if result.status_code == 0:
logger.info(f'The {args[0]} script completed successfully.')
log.info(f'The {args[0]} script completed successfully.')
if result.message:
print(result.message + '!')
if 'NZBOP_SCRIPTDIR' in os.environ: # return code for nzbget v11
del nzb2media.MYAPP
return nzb2media.NZBGET_POSTPROCESS_SUCCESS
else:
logger.error(f'A problem was reported in the {args[0]} script.')
log.error(f'A problem was reported in the {args[0]} script.')
if result.message:
print(result.message + '!')
if 'NZBOP_SCRIPTDIR' in os.environ: # return code for nzbget v11