Added debug logging to subtitles downloading.

pull/222/head
Louis Vézina 6 years ago
parent ab0f5d80e7
commit f95c089874

@ -34,13 +34,13 @@ def check_and_apply_update():
g.fetch('origin')
result = g.diff('--shortstat', 'origin/' + branch)
if len(result) == 0:
logging.info('No new version of Bazarr available.')
logging.info('BAZARR No new version of Bazarr available.')
else:
g.reset('--hard', 'HEAD')
g.checkout(branch)
g.reset('--hard','origin/' + branch)
g.pull()
logging.info('Bazarr updated to latest version and need to be restarted. ' + result)
logging.info('BAZARR Updated to latest version. Restart required. ' + result)
updated()
def updated():

@ -10,15 +10,15 @@ from list_subtitles import list_missing_subtitles, store_subtitles, series_full_
def update_all_episodes():
series_full_scan_subtitles()
logging.info('All existing episode subtitles indexed from disk.')
logging.info('BAZARR All existing episode subtitles indexed from disk.')
list_missing_subtitles()
logging.info('All missing episode subtitles updated in database.')
logging.info('BAZARR All missing episode subtitles updated in database.')
def update_all_movies():
movies_full_scan_subtitles()
logging.info('All existing movie subtitles indexed from disk.')
logging.info('BAZARR All existing movie subtitles indexed from disk.')
list_missing_subtitles()
logging.info('All missing movie subtitles updated in database.')
logging.info('BAZARR All missing movie subtitles updated in database.')
def sync_episodes():
logging.debug('BAZARR Starting episode sync from Sonarr.')
@ -51,13 +51,13 @@ def sync_episodes():
r = requests.get(url_sonarr_api_episode, timeout=15, verify=False)
r.raise_for_status()
except requests.exceptions.HTTPError as errh:
logging.exception("Error trying to get episodes from Sonarr. Http error.")
logging.exception("BAZARR Error trying to get episodes from Sonarr. Http error.")
except requests.exceptions.ConnectionError as errc:
logging.exception("Error trying to get episodes from Sonarr. Connection Error.")
logging.exception("BAZARR Error trying to get episodes from Sonarr. Connection Error.")
except requests.exceptions.Timeout as errt:
logging.exception("Error trying to get episodes from Sonarr. Timeout Error.")
logging.exception("BAZARR Error trying to get episodes from Sonarr. Timeout Error.")
except requests.exceptions.RequestException as err:
logging.exception("Error trying to get episodes from Sonarr.")
logging.exception("BAZARR Error trying to get episodes from Sonarr.")
else:
for episode in r.json():
if 'hasFile' in episode:

@ -28,13 +28,13 @@ def update_movies():
r = requests.get(url_radarr_api_movies, timeout=15, verify=False)
r.raise_for_status()
except requests.exceptions.HTTPError as errh:
logging.exception("Error trying to get movies from Radarr. Http error.")
logging.exception("BAZARR Error trying to get movies from Radarr. Http error.")
except requests.exceptions.ConnectionError as errc:
logging.exception("Error trying to get movies from Radarr. Connection Error.")
logging.exception("BAZARR Error trying to get movies from Radarr. Connection Error.")
except requests.exceptions.Timeout as errt:
logging.exception("Error trying to get movies from Radarr. Timeout Error.")
logging.exception("BAZARR Error trying to get movies from Radarr. Timeout Error.")
except requests.exceptions.RequestException as err:
logging.exception("Error trying to get movies from Radarr.")
logging.exception("BAZARR Error trying to get movies from Radarr.")
else:
# Get current movies in DB
db = sqlite3.connect(os.path.join(config_dir, 'db/bazarr.db'), timeout=30)
@ -137,11 +137,11 @@ def get_profile_list():
try:
profiles_json = requests.get(url_radarr_api_movies, timeout=15, verify=False)
except requests.exceptions.ConnectionError as errc:
logging.exception("Error trying to get profiles from Radarr. Connection Error.")
logging.exception("BAZARR Error trying to get profiles from Radarr. Connection Error.")
except requests.exceptions.Timeout as errt:
logging.exception("Error trying to get profiles from Radarr. Timeout Error.")
logging.exception("BAZARR Error trying to get profiles from Radarr. Timeout Error.")
except requests.exceptions.RequestException as err:
logging.exception("Error trying to get profiles from Radarr.")
logging.exception("BAZARR Error trying to get profiles from Radarr.")
else:
# Parsing data returned from radarr
for profile in profiles_json.json():

@ -27,13 +27,13 @@ def update_series():
r = requests.get(url_sonarr_api_series, timeout=15, verify=False)
r.raise_for_status()
except requests.exceptions.HTTPError as errh:
logging.exception("Error trying to get series from Sonarr. Http error.")
logging.exception("BAZARR Error trying to get series from Sonarr. Http error.")
except requests.exceptions.ConnectionError as errc:
logging.exception("Error trying to get series from Sonarr. Connection Error.")
logging.exception("BAZARR Error trying to get series from Sonarr. Connection Error.")
except requests.exceptions.Timeout as errt:
logging.exception("Error trying to get series from Sonarr. Timeout Error.")
logging.exception("BAZARR Error trying to get series from Sonarr. Timeout Error.")
except requests.exceptions.RequestException as err:
logging.exception("Error trying to get series from Sonarr.")
logging.exception("BAZARR Error trying to get series from Sonarr.")
else:
# Open database connection
db = sqlite3.connect(os.path.join(config_dir, 'db/bazarr.db'), timeout=30)
@ -119,26 +119,26 @@ def get_profile_list():
profiles_json = requests.get(url_sonarr_api_series, timeout=15, verify=False)
except requests.exceptions.ConnectionError as errc:
error = True
logging.exception("Error trying to get profiles from Sonarr. Connection Error.")
logging.exception("BAZARR Error trying to get profiles from Sonarr. Connection Error.")
except requests.exceptions.Timeout as errt:
error = True
logging.exception("Error trying to get profiles from Sonarr. Timeout Error.")
logging.exception("BAZARR Error trying to get profiles from Sonarr. Timeout Error.")
except requests.exceptions.RequestException as err:
error = True
logging.exception("Error trying to get profiles from Sonarr.")
logging.exception("BAZARR Error trying to get profiles from Sonarr.")
url_sonarr_api_series_v3 = url_sonarr + "/api/v3/languageprofile?apikey=" + apikey_sonarr
try:
profiles_json_v3 = requests.get(url_sonarr_api_series_v3, timeout=15, verify=False)
except requests.exceptions.ConnectionError as errc:
error = True
logging.exception("Error trying to get profiles from Sonarr. Connection Error.")
logging.exception("BAZARR Error trying to get profiles from Sonarr. Connection Error.")
except requests.exceptions.Timeout as errt:
error = True
logging.exception("Error trying to get profiles from Sonarr. Timeout Error.")
logging.exception("BAZARR Error trying to get profiles from Sonarr. Timeout Error.")
except requests.exceptions.RequestException as err:
error = True
logging.exception("Error trying to get profiles from Sonarr.")
logging.exception("BAZARR Error trying to get profiles from Sonarr.")
global profiles_list
profiles_list = []

@ -25,6 +25,7 @@ from get_providers import get_providers, get_providers_auth
region.configure('dogpile.cache.memory')
def download_subtitle(path, language, hi, providers, providers_auth, sceneName, media_type):
logging.debug('BAZARR Searching subtitles for this file: ' + path)
if hi == "True":
hi = True
else:
@ -49,7 +50,8 @@ def download_subtitle(path, language, hi, providers, providers_auth, sceneName,
used_sceneName = True
video = Video.fromname(sceneName)
except Exception as e:
logging.exception("Error trying to get video information for this file: " + path)
logging.exception("BAZARR Error trying to get video information for this file: " + path)
pass
else:
if media_type == "movie":
max_score = 120.0
@ -60,7 +62,7 @@ def download_subtitle(path, language, hi, providers, providers_auth, sceneName,
with AsyncProviderPool(max_workers=None, providers=providers, provider_configs=providers_auth) as p:
subtitles = p.list_subtitles(video, language_set)
except Exception as e:
logging.exception("Error trying to get subtitle list from provider")
logging.exception("BAZARR Error trying to get subtitle list from provider for this file: " + path)
else:
subtitles_list = []
sorted_subtitles = sorted([(s, compute_score(s, video, hearing_impaired=hi)) for s in subtitles], key=operator.itemgetter(1), reverse=True)
@ -86,67 +88,78 @@ def download_subtitle(path, language, hi, providers, providers_auth, sceneName,
if any(elem in required for elem in not_matched):
continue
subtitles_list.append(s)
logging.debug('BAZARR ' + str(len(subtitles_list)) + " subtitles have been found for this file: " + path)
if len(subtitles_list) > 0:
best_subtitle = subtitles_list[0]
download_subtitles([best_subtitle], providers=providers, provider_configs=providers_auth)
try:
calculated_score = round(float(compute_score(best_subtitle, video, hearing_impaired=hi)) / max_score * 100, 2)
if used_sceneName == True:
video = scan_video(path)
single = get_general_settings()[7]
if single is True:
result = save_subtitles(video, [best_subtitle], single=True, encoding='utf-8')
else:
result = save_subtitles(video, [best_subtitle], encoding='utf-8')
best_subtitle = subtitles_list[0]
download_subtitles([best_subtitle], providers=providers, provider_configs=providers_auth)
logging.debug('BAZARR Subtitles file downloaded for this file:' + path)
except Exception as e:
logging.exception('Error saving subtitles file to disk.')
logging.exception('BAZARR Error downloading subtitles for this file ' + path)
return None
else:
if len(result) > 0:
downloaded_provider = result[0].provider_name
downloaded_language = language_from_alpha3(result[0].language.alpha3)
downloaded_language_code2 = alpha2_from_alpha3(result[0].language.alpha3)
downloaded_language_code3 = result[0].language.alpha3
downloaded_path = get_subtitle_path(path, language=language_set)
try:
calculated_score = round(float(compute_score(best_subtitle, video, hearing_impaired=hi)) / max_score * 100, 2)
if used_sceneName == True:
message = downloaded_language + " subtitles downloaded from " + downloaded_provider + " with a score of " + unicode(calculated_score) + "% using this scene name: " + sceneName
video = scan_video(path)
single = get_general_settings()[7]
if single is True:
result = save_subtitles(video, [best_subtitle], single=True, encoding='utf-8')
else:
message = downloaded_language + " subtitles downloaded from " + downloaded_provider + " with a score of " + unicode(calculated_score) + "% using filename guessing."
if use_postprocessing is True:
command = pp_replace(postprocessing_cmd, path, downloaded_path, downloaded_language, downloaded_language_code2, downloaded_language_code3)
try:
if os.name == 'nt':
codepage = subprocess.Popen("chcp", shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
result = save_subtitles(video, [best_subtitle], encoding='utf-8')
except Exception as e:
logging.exception('BAZARR Error saving subtitles file to disk for this file:' + path)
pass
else:
if len(result) > 0:
downloaded_provider = result[0].provider_name
downloaded_language = language_from_alpha3(result[0].language.alpha3)
downloaded_language_code2 = alpha2_from_alpha3(result[0].language.alpha3)
downloaded_language_code3 = result[0].language.alpha3
downloaded_path = get_subtitle_path(path, language=language_set)
logging.debug('BAZARR Subtitles file saved to disk: ' + downloaded_path)
if used_sceneName == True:
message = downloaded_language + " subtitles downloaded from " + downloaded_provider + " with a score of " + unicode(calculated_score) + "% using this scene name: " + sceneName
else:
message = downloaded_language + " subtitles downloaded from " + downloaded_provider + " with a score of " + unicode(calculated_score) + "% using filename guessing."
if use_postprocessing is True:
command = pp_replace(postprocessing_cmd, path, downloaded_path, downloaded_language, downloaded_language_code2, downloaded_language_code3)
try:
if os.name == 'nt':
codepage = subprocess.Popen("chcp", shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
# wait for the process to terminate
out_codepage, err_codepage = codepage.communicate()
encoding = out_codepage.split(':')[-1].strip()
process = subprocess.Popen(command, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
# wait for the process to terminate
out_codepage, err_codepage = codepage.communicate()
encoding = out_codepage.split(':')[-1].strip()
process = subprocess.Popen(command, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
# wait for the process to terminate
out, err = process.communicate()
out, err = process.communicate()
if os.name == 'nt':
out = out.decode(encoding)
if os.name == 'nt':
out = out.decode(encoding)
except:
if out == "":
logging.error('Post-processing result for file ' + path + ' : Nothing returned from command execution')
else:
logging.error('Post-processing result for file ' + path + ' : ' + out)
else:
if out == "":
logging.info('Post-processing result for file ' + path + ' : Nothing returned from command execution')
except:
if out == "":
logging.error('BAZARR Post-processing result for file ' + path + ' : Nothing returned from command execution')
else:
logging.error('BAZARR Post-processing result for file ' + path + ' : ' + out)
else:
logging.info('Post-processing result for file ' + path + ' : ' + out)
if out == "":
logging.info('BAZARR Post-processing result for file ' + path + ' : Nothing returned from command execution')
else:
logging.info('BAZARR Post-processing result for file ' + path + ' : ' + out)
return message
else:
return None
return message
else:
logging.error('BAZARR Tried to download best subtitles available for file: ' + path + ' but it had no content. Going to retry on next search.')
return None
else:
return None
logging.debug('BAZARR Ended searching subtitles for file: ' + path)
def manual_search(path, language, hi, providers, providers_auth, sceneName, media_type):
logging.debug('BAZARR Manually searching subtitles for this file: ' + path)
if hi == "True":
hi = True
else:
@ -171,7 +184,7 @@ def manual_search(path, language, hi, providers, providers_auth, sceneName, medi
used_sceneName = True
video = Video.fromname(sceneName)
except:
logging.error("Error trying to get video information.")
logging.exception("BAZARR Error trying to get video information for this file: " + path)
else:
if media_type == "movie":
max_score = 120.0
@ -182,7 +195,7 @@ def manual_search(path, language, hi, providers, providers_auth, sceneName, medi
with AsyncProviderPool(max_workers=None, providers=providers, provider_configs=providers_auth) as p:
subtitles = p.list_subtitles(video, language_set)
except Exception as e:
logging.exception("Error trying to get subtitle list from provider")
logging.exception("BAZARR Error trying to get subtitle list from provider for this file: " + path)
else:
subtitles_list = []
for s in subtitles:
@ -210,9 +223,12 @@ def manual_search(path, language, hi, providers, providers_auth, sceneName, medi
subtitles_list.append(dict(score=round((compute_score(s, video, hearing_impaired=hi) / max_score * 100), 2), language=alpha2_from_alpha3(s.language.alpha3), hearing_impaired=str(s.hearing_impaired), provider=s.provider_name, subtitle=codecs.encode(pickle.dumps(s), "base64").decode(), url=s.page_link, matches=list(matched), dont_matches=list(not_matched)))
subtitles_dict = {}
subtitles_dict = sorted(subtitles_list, key=lambda x: x['score'], reverse=True)
logging.debug('BAZARR ' + str(len(subtitles_dict)) + " subtitles have been found for this file: " + path)
logging.debug('BAZARR Ended searching subtitles for this file: ' + path)
return(subtitles_dict)
def manual_download_subtitle(path, language, hi, subtitle, provider, providers_auth, sceneName, media_type):
logging.debug('BAZARR Manually downloading subtitles for this file: ' + path)
if hi == "True":
hi = True
else:
@ -240,14 +256,15 @@ def manual_download_subtitle(path, language, hi, subtitle, provider, providers_a
used_sceneName = True
video = Video.fromname(sceneName)
except Exception as e:
logging.exception('Error trying to extract information from this filename: ' + path)
return None
logging.exception("BAZARR Error trying to get video information for this file: " + path)
pass
else:
try:
best_subtitle = subtitle
download_subtitles([best_subtitle], providers=provider, provider_configs=providers_auth)
logging.debug('BAZARR Subtitles file downloaded for this file:' + path)
except Exception as e:
logging.exception('Error downloading subtitles for ' + path)
logging.exception('BAZARR Error downloading subtitles for this file ' + path)
return None
else:
single = get_general_settings()[7]
@ -260,7 +277,7 @@ def manual_download_subtitle(path, language, hi, subtitle, provider, providers_a
else:
result = save_subtitles(video, [best_subtitle], encoding='utf-8')
except Exception as e:
logging.exception('Error saving subtitles file to disk.')
logging.exception('BAZARR Error saving subtitles file to disk for this file:' + path)
return None
else:
if len(result) > 0:
@ -269,6 +286,7 @@ def manual_download_subtitle(path, language, hi, subtitle, provider, providers_a
downloaded_language_code2 = alpha2_from_alpha3(result[0].language.alpha3)
downloaded_language_code3 = result[0].language.alpha3
downloaded_path = get_subtitle_path(path, language=lang_obj)
logging.debug('BAZARR Subtitles file saved to disk: ' + downloaded_path)
message = downloaded_language + " subtitles downloaded from " + downloaded_provider + " with a score of " + unicode(score) + "% using manual search."
if use_postprocessing is True:
@ -289,18 +307,20 @@ def manual_download_subtitle(path, language, hi, subtitle, provider, providers_a
except:
if out == "":
logging.error('Post-processing result for file ' + path + ' : Nothing returned from command execution')
logging.error('BAZARR Post-processing result for file ' + path + ' : Nothing returned from command execution')
else:
logging.error('Post-processing result for file ' + path + ' : ' + out)
logging.error('BAZARR Post-processing result for file ' + path + ' : ' + out)
else:
if out == "":
logging.info('Post-processing result for file ' + path + ' : Nothing returned from command execution')
logging.info('BAZARR Post-processing result for file ' + path + ' : Nothing returned from command execution')
else:
logging.info('Post-processing result for file ' + path + ' : ' + out)
logging.info('BAZARR Post-processing result for file ' + path + ' : ' + out)
return message
else:
logging.error('BAZARR Tried to manually download a subtitles for file: ' + path + ' but it had no content. Going to retry on next search.')
return None
logging.debug('BAZARR Ended manually downloading subtitles for file: ' + path)
def series_download_subtitles(no):
if get_general_settings()[24] is True:
@ -426,7 +446,7 @@ def wanted_download_subtitles_movie(path):
history_log_movie(1, movie[3], message)
send_notifications_movie(movie[3], message)
else:
logging.info('Search is not active for movie ' + movie[0] + ' Language: ' + attempt[i][0])
logging.info('BAZARR Search is not active for movie ' + movie[0] + ' Language: ' + attempt[i][0])
def wanted_search_missing_subtitles():
@ -458,7 +478,7 @@ def wanted_search_missing_subtitles():
for movie in movies:
wanted_download_subtitles_movie(movie[0])
logging.info('Finished searching for missing subtitles. Check histories for more information.')
logging.info('BAZARR Finished searching for missing subtitles. Check histories for more information.')
def search_active(timestamp):

@ -12,7 +12,7 @@ if os.path.exists(config_dir) is False:
os.mkdir(os.path.join(config_dir))
logging.debug("BAZARR Created data directory")
except OSError:
logging.exception("The configuration directory doesn't exist and Bazarr cannot create it (permission issue?).")
logging.exception("BAZARR The configuration directory doesn't exist and Bazarr cannot create it (permission issue?).")
exit(2)
if os.path.exists(os.path.join(config_dir, 'config')) is False:
@ -119,7 +119,7 @@ try:
cfg.write(configfile)
logging.info('Config file succesfully migrated from database')
logging.info('BAZARR Config file succesfully migrated from database')
except sqlite3.OperationalError:
if os.path.exists(config_file) is False:
@ -206,7 +206,7 @@ except sqlite3.OperationalError:
with open(config_file, 'w+') as configfile:
cfg.write(configfile)
logging.info('Config file created successfully')
logging.info('BAZARR Config file created successfully')
try:
# Get SQL script from file
fd = open(os.path.join(os.path.dirname(__file__), 'create_db.sql'), 'r')
@ -225,7 +225,7 @@ try:
# Close database connection
db.close()
logging.info('Database created successfully')
logging.info('BAZARR Database created successfully')
except:
pass

@ -55,7 +55,7 @@ def store_subtitles(file):
try:
text = text.decode(encoding.original_encoding)
except Exception as e:
logging.exception('Error trying to detect character encoding for this subtitles file: ' + path_replace(os.path.join(os.path.dirname(file), subtitle)) + ' You should try to delete this subtitles file manually and ask Bazarr to download it again.')
logging.exception('BAZARR Error trying to detect character encoding for this subtitles file: ' + path_replace(os.path.join(os.path.dirname(file), subtitle)) + ' You should try to delete this subtitles file manually and ask Bazarr to download it again.')
else:
detected_language = langdetect.detect(text)
if len(detected_language) > 0:
@ -107,7 +107,7 @@ def store_subtitles_movie(file):
try:
text = text.decode(encoding.original_encoding)
except Exception as e:
logging.exception('Error trying to detect character encoding for this subtitles file: ' + path_replace_movie(os.path.join(os.path.dirname(file), subtitle)) + ' You should try to delete this subtitles file manually and ask Bazarr to download it again.')
logging.exception('BAZARR Error trying to detect character encoding for this subtitles file: ' + path_replace_movie(os.path.join(os.path.dirname(file), subtitle)) + ' You should try to delete this subtitles file manually and ask Bazarr to download it again.')
else:
detected_language = langdetect.detect(text)
if len(detected_language) > 0:

@ -202,7 +202,7 @@ def shutdown():
try:
stop_file = open(os.path.join(config_dir, "bazarr.stop"), "w")
except Exception as e:
logging.error('Cannot create bazarr.stop file.')
logging.error('BAZARR Cannot create bazarr.stop file.')
else:
stop_file.write('')
stop_file.close()
@ -213,12 +213,12 @@ def restart():
try:
server.stop()
except:
logging.error('Cannot stop CherryPy.')
logging.error('BAZARR Cannot stop CherryPy.')
else:
try:
restart_file = open(os.path.join(config_dir, "bazarr.restart"), "w")
except Exception as e:
logging.error('Cannot create bazarr.restart file.')
logging.error('BAZARR Cannot create bazarr.restart file.')
else:
restart_file.write('')
restart_file.close()
@ -236,7 +236,7 @@ def emptylog():
ref = request.environ['HTTP_REFERER']
fh.doRollover()
logging.info('Log file emptied')
logging.info('BAZARR Log file emptied')
redirect(ref)
@ -1298,7 +1298,7 @@ def save_settings():
sonarr_full_update()
radarr_full_update()
logging.info('Settings saved succesfully.')
logging.info('BAZARR Settings saved succesfully.')
# reschedule full update task according to settings
sonarr_full_update()
@ -1425,13 +1425,13 @@ def system():
r = requests.get(url_releases, timeout=15)
r.raise_for_status()
except requests.exceptions.HTTPError as errh:
logging.exception("Error trying to get releases from Github. Http error.")
logging.exception("BAZARR Error trying to get releases from Github. Http error.")
except requests.exceptions.ConnectionError as errc:
logging.exception("Error trying to get releases from Github. Connection Error.")
logging.exception("BAZARR Error trying to get releases from Github. Connection Error.")
except requests.exceptions.Timeout as errt:
logging.exception("Error trying to get releases from Github. Timeout Error.")
logging.exception("BAZARR Error trying to get releases from Github. Timeout Error.")
except requests.exceptions.RequestException as err:
logging.exception("Error trying to get releases from Github.")
logging.exception("BAZARR Error trying to get releases from Github.")
else:
for release in r.json():
releases.append([release['name'],release['body']])
@ -1704,7 +1704,7 @@ warnings.simplefilter("ignore", DeprecationWarning)
server = CherryPyWSGIServer((str(ip), int(port)), app)
try:
logging.info('Bazarr is started and waiting for request on http://' + str(ip) + ':' + str(port) + str(base_url))
logging.info('BAZARR is started and waiting for request on http://' + str(ip) + ':' + str(port) + str(base_url))
print 'Bazarr is started and waiting for request on http://' + str(ip) + ':' + str(port) + str(base_url)
server.start()
except KeyboardInterrupt:

Loading…
Cancel
Save