From 26949970d86ad427f0f9c9b64e3ae4b0060e7eba Mon Sep 17 00:00:00 2001 From: Ozzieisaacs Date: Tue, 11 Jun 2019 18:35:20 +0200 Subject: [PATCH] Revert logging functions Fix access logger for tornado --- cps/__init__.py | 5 +++-- cps/admin.py | 6 ++--- cps/cache_buster.py | 6 ++--- cps/comic.py | 4 ++-- cps/editbooks.py | 14 ++++++------ cps/gdrive.py | 22 +++++++++--------- cps/gdriveutils.py | 16 ++++++------- cps/helper.py | 48 +++++++++++++++++++-------------------- cps/jinjia.py | 4 ++-- cps/logger.py | 55 ++++++++++++++++----------------------------- cps/oauth_bb.py | 12 +++++----- cps/server.py | 45 +++++++++++++++++++++---------------- cps/shelf.py | 28 +++++++++++------------ cps/ub.py | 5 +---- cps/updater.py | 36 ++++++++++++++--------------- cps/uploader.py | 18 +++++++-------- cps/web.py | 24 ++++++++++---------- cps/worker.py | 24 ++++++++++---------- 18 files changed, 180 insertions(+), 192 deletions(-) diff --git a/cps/__init__.py b/cps/__init__.py index dc082507..c6abbdd1 100755 --- a/cps/__init__.py +++ b/cps/__init__.py @@ -88,13 +88,14 @@ from .server import server Server = server() babel = Babel() +log = logger.create() def create_app(): app.wsgi_app = ReverseProxied(app.wsgi_app) cache_buster.init_cache_busting(app) - logger.info('Starting Calibre Web...') + log.info('Starting Calibre Web...') Principal(app) lm.init_app(app) app.secret_key = os.getenv('SECRET_KEY', 'A0Zr98j/3yX R~XHH!jmN]LWX/,?RT') @@ -118,7 +119,7 @@ def get_locale(): try: preferred.append(str(LC.parse(x.replace('-', '_')))) except (UnknownLocaleError, ValueError) as e: - logger.warning('Could not parse locale "%s": %s', x, e) + log.warning('Could not parse locale "%s": %s', x, e) preferred.append('en') return negotiate_locale(preferred, translations) diff --git a/cps/admin.py b/cps/admin.py index dec1fcb3..01f56b7d 100644 --- a/cps/admin.py +++ b/cps/admin.py @@ -76,7 +76,7 @@ except ImportError: feature_support['gdrive'] = gdrive_support admi = Blueprint('admin', __name__) -# log = logger.create() +log = logger.create() @admi.route("/admin") @@ -220,7 +220,7 @@ def view_configuration(): # stop Server Server.setRestartTyp(True) Server.stopServer() - logger.info('Reboot required, restarting') + log.info('Reboot required, restarting') readColumn = db.session.query(db.Custom_Columns)\ .filter(and_(db.Custom_Columns.datatype == 'bool',db.Custom_Columns.mark_for_delete == 0)).all() return render_title_template("config_view_edit.html", conf=config, readColumns=readColumn, @@ -518,7 +518,7 @@ def configuration_helper(origin): # stop Server Server.setRestartTyp(True) Server.stopServer() - logger.info('Reboot required, restarting') + log.info('Reboot required, restarting') if origin: success = True if is_gdrive_ready() and feature_support['gdrive'] is True: # and config.config_use_google_drive == True: diff --git a/cps/cache_buster.py b/cps/cache_buster.py index b8389bbd..02aa7187 100644 --- a/cps/cache_buster.py +++ b/cps/cache_buster.py @@ -24,7 +24,7 @@ import hashlib from . import logger -# log = logger.create() +log = logger.create() def init_cache_busting(app): @@ -40,7 +40,7 @@ def init_cache_busting(app): hash_table = {} # map of file hashes - logger.debug('Computing cache-busting values...') + log.debug('Computing cache-busting values...') # compute file hashes for dirpath, __, filenames in os.walk(static_folder): for filename in filenames: @@ -53,7 +53,7 @@ def init_cache_busting(app): file_path = rooted_filename.replace(static_folder, "") file_path = file_path.replace("\\", "/") # Convert Windows path to web path hash_table[file_path] = file_hash - logger.debug('Finished computing cache-busting values') + log.debug('Finished computing cache-busting values') def bust_filename(filename): return hash_table.get(filename, "") diff --git a/cps/comic.py b/cps/comic.py index d5625cbb..738b2a89 100755 --- a/cps/comic.py +++ b/cps/comic.py @@ -24,14 +24,14 @@ from . import logger, isoLanguages from .constants import BookMeta -# log = logger.create() +log = logger.create() try: from comicapi.comicarchive import ComicArchive, MetaDataStyle use_comic_meta = True except ImportError as e: - logger.warning('cannot import comicapi, extracting comic metadata will not work: %s', e) + log.warning('cannot import comicapi, extracting comic metadata will not work: %s', e) import zipfile import tarfile use_comic_meta = False diff --git a/cps/editbooks.py b/cps/editbooks.py index f6f2a788..e15011fb 100644 --- a/cps/editbooks.py +++ b/cps/editbooks.py @@ -39,7 +39,7 @@ from .web import login_required_if_no_ano, render_title_template, edit_required, editbook = Blueprint('editbook', __name__) -# log = logger.create() +log = logger.create() # Modifies different Database objects, first check if elements have to be added to database, than check @@ -198,7 +198,7 @@ def delete_book(book_id, book_format): db.session.commit() else: # book not found - logger.error('Book with id "%s" could not be deleted: not found', book_id) + log.error('Book with id "%s" could not be deleted: not found', book_id) if book_format: return redirect(url_for('editbook.edit_book', book_id=book_id)) else: @@ -237,7 +237,7 @@ def render_edit_book(book_id): try: allowed_conversion_formats.remove(file.format.lower()) except Exception: - logger.warning('%s already removed from list.', file.format.lower()) + log.warning('%s already removed from list.', file.format.lower()) return render_title_template('book_edit.html', book=book, authors=author_names, cc=cc, title=_(u"edit metadata"), page="editbook", @@ -349,7 +349,7 @@ def upload_single_file(request, book, book_id): # Format entry already exists, no need to update the database if is_format: - logger.warning('Book format %s already existing', file_ext.upper()) + log.warning('Book format %s already existing', file_ext.upper()) else: db_format = db.Data(book_id, file_ext.upper(), file_size, file_name) db.session.add(db_format) @@ -492,7 +492,7 @@ def edit_book(book_id): res = list(language_table[get_locale()].keys())[invers_lang_table.index(lang)] input_l.append(res) except ValueError: - logger.error('%s is not a valid language', lang) + log.error('%s is not a valid language', lang) flash(_(u"%(langname)s is not a valid language", langname=lang), category="error") modify_database_object(input_l, book.languages, db.Languages, db.session, 'languages') @@ -531,7 +531,7 @@ def edit_book(book_id): flash(error, category="error") return render_edit_book(book_id) except Exception as e: - logger.exception(e) + log.exception(e) db.session.rollback() flash(_("Error editing book, please check logfile for details"), category="error") return redirect(url_for('web.show_book', book_id=book.id)) @@ -703,7 +703,7 @@ def convert_bookformat(book_id): flash(_(u"Source or destination format for conversion missing"), category="error") return redirect(request.environ["HTTP_REFERER"]) - logger.info('converting: book id: %s from: %s to: %s', book_id, book_format_from, book_format_to) + log.info('converting: book id: %s from: %s to: %s', book_id, book_format_from, book_format_to) rtn = helper.convert_book_format(book_id, config.config_calibre_dir, book_format_from.upper(), book_format_to.upper(), current_user.nickname) diff --git a/cps/gdrive.py b/cps/gdrive.py index a604dc01..196b9dac 100644 --- a/cps/gdrive.py +++ b/cps/gdrive.py @@ -44,7 +44,7 @@ from .web import admin_required gdrive = Blueprint('gdrive', __name__) -# log = logger.create() +log = logger.create() current_milli_time = lambda: int(round(time() * 1000)) @@ -74,7 +74,7 @@ def google_drive_callback(): with open(gdriveutils.CREDENTIALS, 'w') as f: f.write(credentials.to_json()) except ValueError as error: - logger.error(error) + log.error(error) return redirect(url_for('admin.configuration')) @@ -131,7 +131,7 @@ def revoke_watch_gdrive(): @gdrive.route("/gdrive/watch/callback", methods=['GET', 'POST']) def on_received_watch_confirmation(): - logger.debug('%r', request.headers) + log.debug('%r', request.headers) if request.headers.get('X-Goog-Channel-Token') == gdrive_watch_callback_token \ and request.headers.get('X-Goog-Resource-State') == 'change' \ and request.data: @@ -139,26 +139,26 @@ def on_received_watch_confirmation(): data = request.data def updateMetaData(): - logger.info('Change received from gdrive') - logger.debug('%r', data) + log.info('Change received from gdrive') + log.debug('%r', data) try: j = json.loads(data) - logger.info('Getting change details') + log.info('Getting change details') response = gdriveutils.getChangeById(gdriveutils.Gdrive.Instance().drive, j['id']) - logger.debug('%r', response) + log.debug('%r', response) if response: dbpath = os.path.join(config.config_calibre_dir, "metadata.db") if not response['deleted'] and response['file']['title'] == 'metadata.db' and response['file']['md5Checksum'] != hashlib.md5(dbpath): tmpDir = tempfile.gettempdir() - logger.info('Database file updated') + log.info('Database file updated') copyfile(dbpath, os.path.join(tmpDir, "metadata.db_" + str(current_milli_time()))) - logger.info('Backing up existing and downloading updated metadata.db') + log.info('Backing up existing and downloading updated metadata.db') gdriveutils.downloadFile(None, "metadata.db", os.path.join(tmpDir, "tmp_metadata.db")) - logger.info('Setting up new DB') + log.info('Setting up new DB') # prevent error on windows, as os.rename does on exisiting files move(os.path.join(tmpDir, "tmp_metadata.db"), dbpath) db.setup_db() except Exception as e: - logger.exception(e) + log.exception(e) updateMetaData() return '' diff --git a/cps/gdriveutils.py b/cps/gdriveutils.py index a7036712..705966b2 100644 --- a/cps/gdriveutils.py +++ b/cps/gdriveutils.py @@ -45,7 +45,7 @@ SETTINGS_YAML = os.path.join(_BASE_DIR, 'settings.yaml') CREDENTIALS = os.path.join(_BASE_DIR, 'gdrive_credentials') CLIENT_SECRETS = os.path.join(_BASE_DIR, 'client_secrets.json') -# log = logger.create() +log = logger.create() class Singleton: @@ -169,9 +169,9 @@ def getDrive(drive=None, gauth=None): try: gauth.Refresh() except RefreshError as e: - logger.error("Google Drive error: %s", e) + log.error("Google Drive error: %s", e) except Exception as e: - logger.exception(e) + log.exception(e) else: # Initialize the saved creds gauth.Authorize() @@ -181,7 +181,7 @@ def getDrive(drive=None, gauth=None): try: drive.auth.Refresh() except RefreshError as e: - logger.error("Google Drive error: %s", e) + log.error("Google Drive error: %s", e) return drive def listRootFolders(): @@ -218,7 +218,7 @@ def getEbooksFolderId(drive=None): try: gDriveId.gdrive_id = getEbooksFolder(drive)['id'] except Exception: - logger.error('Error gDrive, root ID not found') + log.error('Error gDrive, root ID not found') gDriveId.path = '/' session.merge(gDriveId) session.commit() @@ -458,10 +458,10 @@ def getChangeById (drive, change_id): change = drive.auth.service.changes().get(changeId=change_id).execute() return change except (errors.HttpError) as error: - logger.error(error) + log.error(error) return None except Exception as e: - logger.error(e) + log.error(e) return None @@ -531,6 +531,6 @@ def do_gdrive_download(df, headers): if resp.status == 206: yield content else: - logger.warning('An error occurred: %s', resp) + log.warning('An error occurred: %s', resp) return return Response(stream_with_context(stream()), headers=headers) diff --git a/cps/helper.py b/cps/helper.py index 09998ff2..eb5374bc 100644 --- a/cps/helper.py +++ b/cps/helper.py @@ -75,7 +75,7 @@ from .worker import STAT_WAITING, STAT_FAIL, STAT_STARTED, STAT_FINISH_SUCCESS from .worker import TASK_EMAIL, TASK_CONVERT, TASK_UPLOAD, TASK_CONVERT_ANY -# log = logger.create() +log = logger.create() def update_download(book_id, user_id): @@ -92,7 +92,7 @@ def convert_book_format(book_id, calibrepath, old_book_format, new_book_format, data = db.session.query(db.Data).filter(db.Data.book == book.id).filter(db.Data.format == old_book_format).first() if not data: error_message = _(u"%(format)s format not found for book id: %(book)d", format=old_book_format, book=book_id) - logger.error("convert_book_format: %s", error_message) + log.error("convert_book_format: %s", error_message) return error_message if config.config_use_google_drive: df = gd.getFileFromEbooksFolder(book.path, data.name + "." + old_book_format.lower()) @@ -186,7 +186,7 @@ def check_send_to_kindle(entry): 'text':_('Convert %(orig)s to %(format)s and send to Kindle',orig='Epub',format='Azw3')})''' return bookformats else: - logger.error(u'Cannot find book entry %d', entry.id) + log.error(u'Cannot find book entry %d', entry.id) return None @@ -272,7 +272,7 @@ def get_sorted_author(value): else: value2 = value except Exception as ex: - logger.error("Sorting author %s failed: %s", value, ex) + log.error("Sorting author %s failed: %s", value, ex) value2 = value return value2 @@ -289,12 +289,12 @@ def delete_book_file(book, calibrepath, book_format=None): else: if os.path.isdir(path): if len(next(os.walk(path))[1]): - logger.error("Deleting book %s failed, path has subfolders: %s", book.id, book.path) + log.error("Deleting book %s failed, path has subfolders: %s", book.id, book.path) return False shutil.rmtree(path, ignore_errors=True) return True else: - logger.error("Deleting book %s failed, book path not valid: %s", book.id, book.path) + log.error("Deleting book %s failed, book path not valid: %s", book.id, book.path) return False @@ -317,7 +317,7 @@ def update_dir_structure_file(book_id, calibrepath, first_author): if not os.path.exists(new_title_path): os.renames(path, new_title_path) else: - logger.info("Copying title: %s into existing: %s", path, new_title_path) + log.info("Copying title: %s into existing: %s", path, new_title_path) for dir_name, __, file_list in os.walk(path): for file in file_list: os.renames(os.path.join(dir_name, file), @@ -325,8 +325,8 @@ def update_dir_structure_file(book_id, calibrepath, first_author): path = new_title_path localbook.path = localbook.path.split('/')[0] + '/' + new_titledir except OSError as ex: - logger.error("Rename title from: %s to %s: %s", path, new_title_path, ex) - logger.debug(ex, exc_info=True) + log.error("Rename title from: %s to %s: %s", path, new_title_path, ex) + log.debug(ex, exc_info=True) return _("Rename title from: '%(src)s' to '%(dest)s' failed with error: %(error)s", src=path, dest=new_title_path, error=str(ex)) if authordir != new_authordir: @@ -335,8 +335,8 @@ def update_dir_structure_file(book_id, calibrepath, first_author): os.renames(path, new_author_path) localbook.path = new_authordir + '/' + localbook.path.split('/')[1] except OSError as ex: - logger.error("Rename author from: %s to %s: %s", path, new_author_path, ex) - logger.debug(ex, exc_info=True) + log.error("Rename author from: %s to %s: %s", path, new_author_path, ex) + log.debug(ex, exc_info=True) return _("Rename author from: '%(src)s' to '%(dest)s' failed with error: %(error)s", src=path, dest=new_author_path, error=str(ex)) # Rename all files from old names to new names @@ -349,8 +349,8 @@ def update_dir_structure_file(book_id, calibrepath, first_author): os.path.join(path_name, new_name + '.' + file_format.format.lower())) file_format.name = new_name except OSError as ex: - logger.error("Rename file in path %s to %s: %s", path, new_name, ex) - logger.debug(ex, exc_info=True) + log.error("Rename file in path %s to %s: %s", path, new_name, ex) + log.debug(ex, exc_info=True) return _("Rename file in path '%(src)s' to '%(dest)s' failed with error: %(error)s", src=path, dest=new_name, error=str(ex)) return False @@ -454,10 +454,10 @@ def get_book_cover(book_id): if path: return redirect(path) else: - logger.error('%s/cover.jpg not found on Google Drive', book.path) + log.error('%s/cover.jpg not found on Google Drive', book.path) return send_from_directory(_STATIC_DIR, "generic_cover.jpg") except Exception as e: - logger.exception(e) + log.exception(e) # traceback.print_exc() return send_from_directory(_STATIC_DIR,"generic_cover.jpg") else: @@ -487,15 +487,15 @@ def save_cover_from_filestorage(filepath, saved_filename, img): try: os.makedirs(filepath) except OSError: - logger.error(u"Failed to create path for cover") + log.error(u"Failed to create path for cover") return False try: img.save(os.path.join(filepath, saved_filename)) except IOError: - logger.error(u"Cover-file is not a valid image file") + log.error(u"Cover-file is not a valid image file") return False except OSError: - logger.error(u"Failed to store cover-file") + log.error(u"Failed to store cover-file") return False return True @@ -506,7 +506,7 @@ def save_cover(img, book_path): if use_PIL: if content_type not in ('image/jpeg', 'image/png', 'image/webp'): - logger.error("Only jpg/jpeg/png/webp files are supported as coverfile") + log.error("Only jpg/jpeg/png/webp files are supported as coverfile") return False # convert to jpg because calibre only supports jpg if content_type in ('image/png', 'image/webp'): @@ -520,7 +520,7 @@ def save_cover(img, book_path): img._content = tmp_bytesio.getvalue() else: if content_type not in ('image/jpeg'): - logger.error("Only jpg/jpeg files are supported as coverfile") + log.error("Only jpg/jpeg files are supported as coverfile") return False if ub.config.config_use_google_drive: @@ -528,7 +528,7 @@ def save_cover(img, book_path): if save_cover_from_filestorage(tmpDir, "uploaded_cover.jpg", img) is True: gd.uploadFileToEbooksFolder(os.path.join(book_path, 'cover.jpg'), os.path.join(tmpDir, "uploaded_cover.jpg")) - logger.info("Cover is saved on Google Drive") + log.info("Cover is saved on Google Drive") return True else: return False @@ -541,7 +541,7 @@ def do_download_file(book, book_format, data, headers): if config.config_use_google_drive: startTime = time.time() df = gd.getFileFromEbooksFolder(book.path, data.name + "." + book_format) - logger.debug('%s', time.time() - startTime) + log.debug('%s', time.time() - startTime) if df: return gd.do_gdrive_download(df, headers) else: @@ -550,7 +550,7 @@ def do_download_file(book, book_format, data, headers): filename = os.path.join(config.config_calibre_dir, book.path) if not os.path.isfile(os.path.join(filename, data.name + "." + book_format)): # ToDo: improve error handling - logger.error('File not found: %s', os.path.join(filename, data.name + "." + book_format)) + log.error('File not found: %s', os.path.join(filename, data.name + "." + book_format)) response = make_response(send_from_directory(filename, data.name + "." + book_format)) response.headers = headers return response @@ -575,7 +575,7 @@ def check_unrar(unrarLocation): version = value.group(1) except OSError as e: error = True - logger.exception(e) + log.exception(e) version =_(u'Error excecuting UnRar') else: version = _(u'Unrar binary file not found') diff --git a/cps/jinjia.py b/cps/jinjia.py index 04f8c2f0..37f9ce30 100644 --- a/cps/jinjia.py +++ b/cps/jinjia.py @@ -37,7 +37,7 @@ from . import logger jinjia = Blueprint('jinjia', __name__) -# log = logger.create() +log = logger.create() # pagination links in jinja @@ -85,7 +85,7 @@ def formatdate_filter(val): formatdate = datetime.datetime.strptime(conformed_timestamp[:15], "%Y%m%d %H%M%S") return format_date(formatdate, format='medium', locale=get_locale()) except AttributeError as e: - logger.error('Babel error: %s, Current user locale: %s, Current User: %s', e, current_user.locale, current_user.nickname) + log.error('Babel error: %s, Current user locale: %s, Current User: %s', e, current_user.locale, current_user.nickname) return formatdate @jinjia.app_template_filter('formatdateinput') diff --git a/cps/logger.py b/cps/logger.py index 4bb95bce..2073b066 100644 --- a/cps/logger.py +++ b/cps/logger.py @@ -25,7 +25,9 @@ from logging.handlers import RotatingFileHandler from .constants import BASE_DIR as _BASE_DIR -ACCESS_FORMATTER = Formatter("%(message)s") +ACCESS_FORMATTER_GEVENT = Formatter("%(message)s") +ACCESS_FORMATTER_TORNADO = Formatter("[%(asctime)s] %(message)s") + FORMATTER = Formatter("[%(asctime)s] %(levelname)5s {%(name)s:%(lineno)d} %(message)s") DEFAULT_LOG_LEVEL = logging.INFO DEFAULT_LOG_FILE = os.path.join(_BASE_DIR, "calibre-web.log") @@ -37,38 +39,12 @@ logging.addLevelName(logging.WARNING, "WARN") logging.addLevelName(logging.CRITICAL, "CRIT") -def info(msg, *args, **kwargs): - create(2).info(msg, *args, **kwargs) - - -def warning(msg, *args, **kwargs): - create(2).warning(msg, *args, **kwargs) - - -def error(msg, *args, **kwargs): - create(2).error(msg, *args, **kwargs) - - -def critical(msg, *args, **kwargs): - create(2).critical(msg, *args, **kwargs) - - -def exception(msg, *args, **kwargs): - create(2).exception(msg, *args, **kwargs) - - -def debug(msg, *args, **kwargs): - create(2).debug(msg, *args, **kwargs) - - def get(name=None): - val = logging.getLogger("general") - val.name = name - return val + return logging.getLogger(name) -def create(ini=1): - parent_frame = inspect.stack(0)[ini] +def create(): + parent_frame = inspect.stack(0)[1] if hasattr(parent_frame, 'frame'): parent_frame = parent_frame.frame else: @@ -77,8 +53,8 @@ def create(ini=1): return get(parent_module.__name__) -def is_debug_enabled(logger): - return logging.getLogger(logger).level <= logging.DEBUG +def is_debug_enabled(): + return logging.root.level <= logging.DEBUG def is_info_enabled(logger): return logging.getLogger(logger).level <= logging.INFO @@ -97,12 +73,15 @@ def is_valid_logfile(file_path): return (not log_dir) or os.path.isdir(log_dir) -def setup(log_file, logger, log_level=None): - if logger == "general": +def setup(log_file, log_level=None, logger=None): + if logger != "access" and logger != "tornado.access": formatter = FORMATTER default_file = DEFAULT_LOG_FILE else: - formatter = ACCESS_FORMATTER + if logger == "tornado.access": + formatter = ACCESS_FORMATTER_TORNADO + else: + formatter = ACCESS_FORMATTER_GEVENT default_file = DEFAULT_ACCESS_LOG if log_file: if not os.path.dirname(log_file): @@ -113,7 +92,11 @@ def setup(log_file, logger, log_level=None): log_file = default_file # print ('%r -- %r' % (log_level, log_file)) - r = logging.getLogger(logger) + if logger != "access" and logger != "tornado.access": + r = logging.root + else: + r = logging.getLogger(logger) + r.propagate = False r.setLevel(log_level or DEFAULT_LOG_LEVEL) previous_handler = r.handlers[0] if r.handlers else None diff --git a/cps/oauth_bb.py b/cps/oauth_bb.py index d9db3e0e..3a48798a 100644 --- a/cps/oauth_bb.py +++ b/cps/oauth_bb.py @@ -42,7 +42,7 @@ from .web import login_required oauth_check = {} oauth = Blueprint('oauth', __name__) -# log = logger.create() +log = logger.create() def github_oauth_required(f): @@ -105,7 +105,7 @@ def register_user_with_oauth(user=None): try: ub.session.commit() except Exception as e: - logger.exception(e) + log.exception(e) ub.session.rollback() @@ -199,7 +199,7 @@ if ub.oauth_support: ub.session.add(oauth) ub.session.commit() except Exception as e: - logger.exception(e) + log.exception(e) ub.session.rollback() # Disable Flask-Dance's default behavior for saving the OAuth token @@ -225,7 +225,7 @@ if ub.oauth_support: ub.session.add(oauth) ub.session.commit() except Exception as e: - logger.exception(e) + log.exception(e) ub.session.rollback() return redirect(url_for('web.login')) #if config.config_public_reg: @@ -268,11 +268,11 @@ if ub.oauth_support: logout_oauth_user() flash(_(u"Unlink to %(oauth)s success.", oauth=oauth_check[provider]), category="success") except Exception as e: - logger.exception(e) + log.exception(e) ub.session.rollback() flash(_(u"Unlink to %(oauth)s failed.", oauth=oauth_check[provider]), category="error") except NoResultFound: - logger.warning("oauth %s for user %d not fount", provider, current_user.id) + log.warning("oauth %s for user %d not fount", provider, current_user.id) flash(_(u"Not linked to %(oauth)s.", oauth=oauth_check[provider]), category="error") return redirect(url_for('web.profile')) diff --git a/cps/server.py b/cps/server.py index a8d4cc16..88c54c78 100644 --- a/cps/server.py +++ b/cps/server.py @@ -34,11 +34,16 @@ except ImportError: from tornado.httpserver import HTTPServer from tornado.ioloop import IOLoop from tornado import version as tornadoVersion + from tornado import log as tornadoLog + from tornado import options as tornadoOptions gevent_present = False from . import logger, config, global_WorkerThread +log = logger.create() + + class server: wsgiserver = None @@ -54,10 +59,13 @@ class server: self.app = application self.port = config.config_port self.listening = config.get_config_ipaddress(readable=True) + ":" + str(self.port) + self.access_logger = None if config.config_access_log: - self.access_logger = logging.getLogger("access") - else: - self.access_logger = None + if gevent_present: + logger.setup(config.config_access_logfile, logger.DEFAULT_ACCESS_LEVEL, "access") + self.access_logger = logging.getLogger("access") + else: + logger.setup(config.config_access_logfile, logger.DEFAULT_ACCESS_LEVEL, "tornado.access") self.ssl_args = None certfile_path = config.get_config_certfile() @@ -67,9 +75,9 @@ class server: self.ssl_args = {"certfile": certfile_path, "keyfile": keyfile_path} else: - logger.warning('The specified paths for the ssl certificate file and/or key file seem to be broken. Ignoring ssl.') - logger.warning('Cert path: %s', certfile_path) - logger.warning('Key path: %s', keyfile_path) + log.warning('The specified paths for the ssl certificate file and/or key file seem to be broken. Ignoring ssl.') + log.warning('Cert path: %s', certfile_path) + log.warning('Key path: %s', keyfile_path) def _make_gevent_socket(self): if config.get_config_ipaddress(): @@ -80,15 +88,15 @@ class server: try: s = WSGIServer.get_listener(('', self.port), family=socket.AF_INET6) except socket.error as ex: - logger.error('%s', ex) - logger.warning('Unable to listen on \'\', trying on IPv4 only...') + log.error('%s', ex) + log.warning('Unable to listen on \'\', trying on IPv4 only...') s = WSGIServer.get_listener(('', self.port), family=socket.AF_INET) - logger.debug("%r %r", s._sock, s._sock.getsockname()) + log.debug("%r %r", s._sock, s._sock.getsockname()) return s def start_gevent(self): ssl_args = self.ssl_args or {} - logger.info('Starting Gevent server on %s', self.listening) + log.info('Starting Gevent server') try: sock = self._make_gevent_socket() @@ -96,35 +104,34 @@ class server: self.wsgiserver.serve_forever() except socket.error: try: - logger.info('Unable to listen on "", trying on "0.0.0.0" only...') + log.info('Unable to listen on "", trying on "0.0.0.0" only...') self.wsgiserver = WSGIServer(('0.0.0.0', config.config_port), self.app, spawn=Pool(), **ssl_args) self.wsgiserver.serve_forever() except (OSError, socket.error) as e: - logger.info("Error starting server: %s", e.strerror) + log.info("Error starting server: %s", e.strerror) print("Error starting server: %s" % e.strerror) global_WorkerThread.stop() sys.exit(1) except Exception: - logger.exception("Unknown error while starting gevent") + log.exception("Unknown error while starting gevent") sys.exit(0) def start_tornado(self): - logger.info('Starting Tornado server on %s', self.listening) + log.info('Starting Tornado server on %s', self.listening) try: - # Max Buffersize set to 200MB + # Max Buffersize set to 200MB ) http_server = HTTPServer(WSGIContainer(self.app), max_buffer_size = 209700000, ssl_options=self.ssl_args) address = config.get_config_ipaddress() http_server.listen(self.port, address) - # self.access_log = logging.getLogger("tornado.access") self.wsgiserver=IOLoop.instance() self.wsgiserver.start() # wait for stop signal self.wsgiserver.close(True) except socket.error as err: - logger.exception("Error starting tornado server") + log.exception("Error starting tornado server") print("Error starting server: %s" % err.strerror) global_WorkerThread.stop() sys.exit(1) @@ -137,7 +144,7 @@ class server: self.start_tornado() if self.restart is True: - logger.info("Performing restart of Calibre-Web") + log.info("Performing restart of Calibre-Web") global_WorkerThread.stop() if os.name == 'nt': arguments = ["\"" + sys.executable + "\""] @@ -147,7 +154,7 @@ class server: else: os.execl(sys.executable, sys.executable, *sys.argv) else: - logger.info("Performing shutdown of Calibre-Web") + log.info("Performing shutdown of Calibre-Web") global_WorkerThread.stop() sys.exit(0) diff --git a/cps/shelf.py b/cps/shelf.py index 0c4cdaa0..a34dbfed 100644 --- a/cps/shelf.py +++ b/cps/shelf.py @@ -33,7 +33,7 @@ from .web import render_title_template shelf = Blueprint('shelf', __name__) -# log = logger.create() +log = logger.create() @shelf.route("/shelf/add//") @@ -41,14 +41,14 @@ shelf = Blueprint('shelf', __name__) def add_to_shelf(shelf_id, book_id): shelf = ub.session.query(ub.Shelf).filter(ub.Shelf.id == shelf_id).first() if shelf is None: - logger.error("Invalid shelf specified: %s", shelf_id) + log.error("Invalid shelf specified: %s", shelf_id) if not request.is_xhr: flash(_(u"Invalid shelf specified"), category="error") return redirect(url_for('web.index')) return "Invalid shelf specified", 400 if not shelf.is_public and not shelf.user_id == int(current_user.id): - logger.error("User %s not allowed to add a book to %s", current_user, shelf) + log.error("User %s not allowed to add a book to %s", current_user, shelf) if not request.is_xhr: flash(_(u"Sorry you are not allowed to add a book to the the shelf: %(shelfname)s", shelfname=shelf.name), category="error") @@ -56,7 +56,7 @@ def add_to_shelf(shelf_id, book_id): return "Sorry you are not allowed to add a book to the the shelf: %s" % shelf.name, 403 if shelf.is_public and not current_user.role_edit_shelfs(): - logger.info("User %s not allowed to edit public shelves", current_user) + log.info("User %s not allowed to edit public shelves", current_user) if not request.is_xhr: flash(_(u"You are not allowed to edit public shelves"), category="error") return redirect(url_for('web.index')) @@ -65,7 +65,7 @@ def add_to_shelf(shelf_id, book_id): book_in_shelf = ub.session.query(ub.BookShelf).filter(ub.BookShelf.shelf == shelf_id, ub.BookShelf.book_id == book_id).first() if book_in_shelf: - logger.error("Book %s is already part of %s", book_id, shelf) + log.error("Book %s is already part of %s", book_id, shelf) if not request.is_xhr: flash(_(u"Book is already part of the shelf: %(shelfname)s", shelfname=shelf.name), category="error") return redirect(url_for('web.index')) @@ -94,17 +94,17 @@ def add_to_shelf(shelf_id, book_id): def search_to_shelf(shelf_id): shelf = ub.session.query(ub.Shelf).filter(ub.Shelf.id == shelf_id).first() if shelf is None: - logger.error("Invalid shelf specified: %s", shelf_id) + log.error("Invalid shelf specified: %s", shelf_id) flash(_(u"Invalid shelf specified"), category="error") return redirect(url_for('web.index')) if not shelf.is_public and not shelf.user_id == int(current_user.id): - logger.error("User %s not allowed to add a book to %s", current_user, shelf) + log.error("User %s not allowed to add a book to %s", current_user, shelf) flash(_(u"You are not allowed to add a book to the the shelf: %(name)s", name=shelf.name), category="error") return redirect(url_for('web.index')) if shelf.is_public and not current_user.role_edit_shelfs(): - logger.error("User %s not allowed to edit public shelves", current_user) + log.error("User %s not allowed to edit public shelves", current_user) flash(_(u"User is not allowed to edit public shelves"), category="error") return redirect(url_for('web.index')) @@ -122,7 +122,7 @@ def search_to_shelf(shelf_id): books_for_shelf = searched_ids[current_user.id] if not books_for_shelf: - logger.error("Books are already part of %s", shelf) + log.error("Books are already part of %s", shelf) flash(_(u"Books are already part of the shelf: %(name)s", name=shelf.name), category="error") return redirect(url_for('web.index')) @@ -148,7 +148,7 @@ def search_to_shelf(shelf_id): def remove_from_shelf(shelf_id, book_id): shelf = ub.session.query(ub.Shelf).filter(ub.Shelf.id == shelf_id).first() if shelf is None: - logger.error("Invalid shelf specified: %s", shelf_id) + log.error("Invalid shelf specified: %s", shelf_id) if not request.is_xhr: return redirect(url_for('web.index')) return "Invalid shelf specified", 400 @@ -167,7 +167,7 @@ def remove_from_shelf(shelf_id, book_id): ub.BookShelf.book_id == book_id).first() if book_shelf is None: - logger.error("Book %s already removed from %s", book_id, shelf) + log.error("Book %s already removed from %s", book_id, shelf) if not request.is_xhr: return redirect(url_for('web.index')) return "Book already removed from shelf", 410 @@ -180,7 +180,7 @@ def remove_from_shelf(shelf_id, book_id): return redirect(request.environ["HTTP_REFERER"]) return "", 204 else: - logger.error("User %s not allowed to remove a book from %s", current_user, shelf) + log.error("User %s not allowed to remove a book from %s", current_user, shelf) if not request.is_xhr: flash(_(u"Sorry you are not allowed to remove a book from this shelf: %(sname)s", sname=shelf.name), category="error") @@ -262,7 +262,7 @@ def delete_shelf(shelf_id): if deleted: ub.session.query(ub.BookShelf).filter(ub.BookShelf.shelf == shelf_id).delete() ub.session.commit() - logger.info("successfully deleted %s", cur_shelf) + log.info("successfully deleted %s", cur_shelf) return redirect(url_for('web.index')) # @shelf.route("/shelfdown/") @@ -289,7 +289,7 @@ def show_shelf(shelf_type, shelf_id): if cur_book: result.append(cur_book) else: - logger.info('Not existing book %s in %s deleted', book.book_id, shelf) + log.info('Not existing book %s in %s deleted', book.book_id, shelf) ub.session.query(ub.BookShelf).filter(ub.BookShelf.book_id == book.book_id).delete() ub.session.commit() return render_title_template(page, entries=result, title=_(u"Shelf: '%(name)s'", name=shelf.name), diff --git a/cps/ub.py b/cps/ub.py index 502b7893..f3ed6380 100644 --- a/cps/ub.py +++ b/cps/ub.py @@ -39,7 +39,6 @@ from sqlalchemy import String, Integer, SmallInteger, Boolean, DateTime from sqlalchemy.orm import relationship, sessionmaker from sqlalchemy.ext.declarative import declarative_base from werkzeug.security import generate_password_hash -import logging try: import ldap @@ -446,9 +445,7 @@ class Config: self.config_rarfile_location = data.config_rarfile_location self.config_theme = data.config_theme self.config_updatechannel = data.config_updatechannel - logger.setup(self.config_logfile, "general", self.config_log_level) - if self.config_access_log: - logger.setup("access.log", "access", logger.DEFAULT_ACCESS_LEVEL) + logger.setup(self.config_logfile, self.config_log_level) @property def get_update_channel(self): diff --git a/cps/updater.py b/cps/updater.py index 2c524c48..28be3b3a 100644 --- a/cps/updater.py +++ b/cps/updater.py @@ -36,7 +36,7 @@ from flask_babel import gettext as _ from . import constants, logger, config, get_locale, Server -# log = logger.create() +log = logger.create() _REPOSITORY_API_URL = 'https://api.github.com/repos/janeczku/calibre-web' @@ -72,45 +72,45 @@ class Updater(threading.Thread): def run(self): try: self.status = 1 - logger.debug(u'Download update file') + log.debug(u'Download update file') headers = {'Accept': 'application/vnd.github.v3+json'} r = requests.get(self._get_request_path(), stream=True, headers=headers) r.raise_for_status() self.status = 2 - logger.debug(u'Opening zipfile') + log.debug(u'Opening zipfile') z = zipfile.ZipFile(BytesIO(r.content)) self.status = 3 - logger.debug(u'Extracting zipfile') + log.debug(u'Extracting zipfile') tmp_dir = gettempdir() z.extractall(tmp_dir) foldername = os.path.join(tmp_dir, z.namelist()[0])[:-1] if not os.path.isdir(foldername): self.status = 11 - logger.error(u'Extracted contents of zipfile not found in temp folder') + log.info(u'Extracted contents of zipfile not found in temp folder') return self.status = 4 - logger.debug(u'Replacing files') + log.debug(u'Replacing files') self.update_source(foldername, constants.BASE_DIR) self.status = 6 - logger.debug(u'Preparing restart of server') + log.debug(u'Preparing restart of server') time.sleep(2) Server.setRestartTyp(True) Server.stopServer() self.status = 7 time.sleep(2) except requests.exceptions.HTTPError as ex: - logger.info(u'HTTP Error %s', ex) + log.info(u'HTTP Error %s', ex) self.status = 8 except requests.exceptions.ConnectionError: - logger.info(u'Connection error') + log.info(u'Connection error') self.status = 9 except requests.exceptions.Timeout: - logger.info(u'Timeout while establishing connection') + log.info(u'Timeout while establishing connection') self.status = 10 except requests.exceptions.RequestException: self.status = 11 - logger.info(u'General error') + log.info(u'General error') def get_update_status(self): return self.status @@ -159,12 +159,12 @@ class Updater(threading.Thread): if sys.platform == "win32" or sys.platform == "darwin": change_permissions = False else: - logger.debug('Update on OS-System : %s', sys.platform) + log.debug('Update on OS-System : %s', sys.platform) for src_dir, __, files in os.walk(root_src_dir): dst_dir = src_dir.replace(root_src_dir, root_dst_dir, 1) if not os.path.exists(dst_dir): os.makedirs(dst_dir) - logger.debug('Create-Dir: %s', dst_dir) + log.debug('Create-Dir: %s', dst_dir) if change_permissions: # print('Permissions: User '+str(new_permissions.st_uid)+' Group '+str(new_permissions.st_uid)) os.chown(dst_dir, new_permissions.st_uid, new_permissions.st_gid) @@ -173,19 +173,19 @@ class Updater(threading.Thread): dst_file = os.path.join(dst_dir, file_) permission = os.stat(dst_file) if os.path.exists(dst_file): - logger.debug('Remove file before copy: %s', dst_file) + log.debug('Remove file before copy: %s', dst_file) os.remove(dst_file) else: if change_permissions: permission = new_permissions shutil.move(src_file, dst_dir) - logger.debug('Move File %s to %s', src_file, dst_dir) + log.debug('Move File %s to %s', src_file, dst_dir) if change_permissions: try: os.chown(dst_file, permission.st_uid, permission.st_gid) except OSError as e: old_permissions = os.stat(dst_file) - logger.debug('Fail change permissions of %s. Before: %s:%s After %s:%s error: %s', + log.debug('Fail change permissions of %s. Before: %s:%s After %s:%s error: %s', dst_file, old_permissions.st_uid, old_permissions.st_gid, permission.st_uid, permission.st_gid, e) return @@ -221,11 +221,11 @@ class Updater(threading.Thread): for item in remove_items: item_path = os.path.join(destination, item[1:]) if os.path.isdir(item_path): - logger.debug("Delete dir %s", item_path) + log.debug("Delete dir %s", item_path) shutil.rmtree(item_path, ignore_errors=True) else: try: - logger.debug("Delete file %s", item_path) + log.debug("Delete file %s", item_path) # log_from_thread("Delete file " + item_path) os.remove(item_path) except OSError: diff --git a/cps/uploader.py b/cps/uploader.py index 2b47ed1d..17816d0a 100644 --- a/cps/uploader.py +++ b/cps/uploader.py @@ -28,7 +28,7 @@ from . import logger, comic from .constants import BookMeta -# log = logger.create() +log = logger.create() try: @@ -42,7 +42,7 @@ try: from wand.exceptions import PolicyError use_generic_pdf_cover = False except (ImportError, RuntimeError) as e: - logger.warning('cannot import Image, generating pdf covers for pdf uploads will not work: %s', e) + log.warning('cannot import Image, generating pdf covers for pdf uploads will not work: %s', e) use_generic_pdf_cover = True try: @@ -50,21 +50,21 @@ try: from PyPDF2 import __version__ as PyPdfVersion use_pdf_meta = True except ImportError as e: - logger.warning('cannot import PyPDF2, extracting pdf metadata will not work: %s', e) + log.warning('cannot import PyPDF2, extracting pdf metadata will not work: %s', e) use_pdf_meta = False try: from . import epub use_epub_meta = True except ImportError as e: - logger.warning('cannot import epub, extracting epub metadata will not work: %s', e) + log.warning('cannot import epub, extracting epub metadata will not work: %s', e) use_epub_meta = False try: from . import fb2 use_fb2_meta = True except ImportError as e: - logger.warning('cannot import fb2, extracting fb2 metadata will not work: %s', e) + log.warning('cannot import fb2, extracting fb2 metadata will not work: %s', e) use_fb2_meta = False try: @@ -72,7 +72,7 @@ try: from PIL import __version__ as PILversion use_PIL = True except ImportError as e: - logger.warning('cannot import Pillow, using png and webp images as cover will not work: %s', e) + log.warning('cannot import Pillow, using png and webp images as cover will not work: %s', e) use_generic_pdf_cover = True use_PIL = False @@ -94,7 +94,7 @@ def process(tmp_file_path, original_file_name, original_file_extension): meta = comic.get_comic_info(tmp_file_path, original_file_name, original_file_extension) except Exception as ex: - logger.warning('cannot parse metadata, using default: %s', ex) + log.warning('cannot parse metadata, using default: %s', ex) if meta and meta.title.strip() and meta.author.strip(): return meta @@ -198,10 +198,10 @@ def pdf_preview(tmp_file_path, tmp_dir): img.save(filename=os.path.join(tmp_dir, cover_file_name)) return cover_file_name except PolicyError as ex: - logger.warning('Pdf extraction forbidden by Imagemagick policy: %s', ex) + log.warning('Pdf extraction forbidden by Imagemagick policy: %s', ex) return None except Exception as ex: - logger.warning('Cannot extract cover image, using default: %s', ex) + log.warning('Cannot extract cover image, using default: %s', ex) return None diff --git a/cps/web.py b/cps/web.py index ee123877..e0c953cc 100644 --- a/cps/web.py +++ b/cps/web.py @@ -105,7 +105,7 @@ for ex in default_exceptions: web = Blueprint('web', __name__) -# log = logger.create() +log = logger.create() # ################################### Login logic and rights management ############################################### @@ -308,7 +308,7 @@ def toggle_read(book_id): db.session.add(new_cc) db.session.commit() except KeyError: - logger.error(u"Custom Column No.%d is not exisiting in calibre database", config.config_read_column) + log.error(u"Custom Column No.%d is not exisiting in calibre database", config.config_read_column) return "" ''' @@ -331,10 +331,10 @@ def get_comic_book(book_id, book_format, page): extract = lambda page: rf.read(names[page]) except: # rarfile not valid - logger.error('Unrar binary not found, or unable to decompress file %s', cbr_file) + log.error('Unrar binary not found, or unable to decompress file %s', cbr_file) return "", 204 else: - logger.info('Unrar is not supported please install python rarfile extension') + log.info('Unrar is not supported please install python rarfile extension') # no support means return nothing return "", 204 elif book_format in ("cbz", "zip"): @@ -346,7 +346,7 @@ def get_comic_book(book_id, book_format, page): names=sort(tf.getnames()) extract = lambda page: tf.extractfile(names[page]).read() else: - logger.error('unsupported comic format') + log.error('unsupported comic format') return "", 204 if sys.version_info.major >= 3: @@ -937,7 +937,7 @@ def render_read_books(page, are_read, as_xml=False, order=None): .filter(db.cc_classes[config.config_read_column].value is True).all() readBookIds = [x.book for x in readBooks] except KeyError: - logger.error("Custom Column No.%d is not existing in calibre database", config.config_read_column) + log.error("Custom Column No.%d is not existing in calibre database", config.config_read_column) readBookIds = [] if are_read: @@ -980,7 +980,7 @@ def serve_book(book_id, book_format): book = db.session.query(db.Books).filter(db.Books.id == book_id).first() data = db.session.query(db.Data).filter(db.Data.book == book.id).filter(db.Data.format == book_format.upper())\ .first() - logger.info('Serving book: %s', data.name) + log.info('Serving book: %s', data.name) if config.config_use_google_drive: headers = Headers() try: @@ -1063,7 +1063,7 @@ def register(): return render_title_template('register.html', title=_(u"register"), page="register") else: flash(_(u"Your e-mail is not allowed to register"), category="error") - logger.info('Registering failed for user "%s" e-mail adress: %s', to_save['nickname'], to_save["email"]) + log.info('Registering failed for user "%s" e-mail adress: %s', to_save['nickname'], to_save["email"]) return render_title_template('register.html', title=_(u"register"), page="register") flash(_(u"Confirmation e-mail was send to your e-mail account."), category="success") return redirect(url_for('web.login')) @@ -1095,10 +1095,10 @@ def login(): return redirect_back(url_for("web.index")) except ldap.INVALID_CREDENTIALS: ipAdress = request.headers.get('X-Forwarded-For', request.remote_addr) - logger.info('LDAP Login failed for user "%s" IP-adress: %s', form['username'], ipAdress) + log.info('LDAP Login failed for user "%s" IP-adress: %s', form['username'], ipAdress) flash(_(u"Wrong Username or Password"), category="error") except ldap.SERVER_DOWN: - logger.info('LDAP Login failed, LDAP Server down') + log.info('LDAP Login failed, LDAP Server down') flash(_(u"Could not login. LDAP server down, please contact your administrator"), category="error") else: if user and check_password_hash(user.password, form['password']) and user.nickname is not "Guest": @@ -1107,7 +1107,7 @@ def login(): return redirect_back(url_for("web.index")) else: ipAdress = request.headers.get('X-Forwarded-For', request.remote_addr) - logger.info('Login failed for user "%s" IP-adress: %s', form['username'], ipAdress) + log.info('Login failed for user "%s" IP-adress: %s', form['username'], ipAdress) flash(_(u"Wrong Username or Password"), category="error") next_url = url_for('web.index') @@ -1348,7 +1348,7 @@ def show_book(book_id): matching_have_read_book = getattr(entries, 'custom_column_'+str(config.config_read_column)) have_read = len(matching_have_read_book) > 0 and matching_have_read_book[0].value except KeyError: - logger.error("Custom Column No.%d is not exisiting in calibre database", config.config_read_column) + log.error("Custom Column No.%d is not exisiting in calibre database", config.config_read_column) have_read = None else: diff --git a/cps/worker.py b/cps/worker.py index 760f1a0a..a33ad99d 100644 --- a/cps/worker.py +++ b/cps/worker.py @@ -48,7 +48,7 @@ from . import logger, config, db, gdriveutils from .subproc_wrapper import process_open -# log = logger.create() +log = logger.create() chunksize = 8192 # task 'status' consts @@ -90,8 +90,8 @@ def get_attachment(bookpath, filename): data = file_.read() file_.close() except IOError as e: - logger.exception(e) # traceback.print_exc() - logger.error(u'The requested file could not be read. Maybe wrong permissions?') + log.exception(e) # traceback.print_exc() + log.error(u'The requested file could not be read. Maybe wrong permissions?') return None attachment = MIMEBase('application', 'octet-stream') @@ -116,7 +116,7 @@ class emailbase(): def send(self, strg): """Send `strg' to the server.""" - logger.debug('send: %r', strg[:300]) + log.debug('send: %r', strg[:300]) if hasattr(self, 'sock') and self.sock: try: if self.transferSize: @@ -142,7 +142,7 @@ class emailbase(): @classmethod def _print_debug(self, *args): - logger.debug(args) + log.debug(args) def getTransferStatus(self): if self.transferSize: @@ -257,14 +257,14 @@ class WorkerThread(threading.Thread): # if it does - mark the conversion task as complete and return a success # this will allow send to kindle workflow to continue to work if os.path.isfile(file_path + format_new_ext): - logger.info("Book id %d already converted to %s", bookid, format_new_ext) + log.info("Book id %d already converted to %s", bookid, format_new_ext) cur_book = db.session.query(db.Books).filter(db.Books.id == bookid).first() self.queue[self.current]['path'] = file_path self.queue[self.current]['title'] = cur_book.title self._handleSuccess() return file_path + format_new_ext else: - logger.info("Book id %d - target format of %s does not exist. Moving forward with convert.", bookid, format_new_ext) + log.info("Book id %d - target format of %s does not exist. Moving forward with convert.", bookid, format_new_ext) # check if converter-executable is existing if not os.path.exists(config.config_converterpath): @@ -320,13 +320,13 @@ class WorkerThread(threading.Thread): if conv_error: error_message = _(u"Kindlegen failed with Error %(error)s. Message: %(message)s", error=conv_error.group(1), message=conv_error.group(2).strip()) - logger.debug("convert_kindlegen: %s", nextline) + log.debug("convert_kindlegen: %s", nextline) else: while p.poll() is None: nextline = p.stdout.readline() if os.name == 'nt' and sys.version_info < (3, 0): nextline = nextline.decode('windows-1252') - logger.debug(nextline.strip('\r\n')) + log.debug(nextline.strip('\r\n')) # parse progress string from calibre-converter progress = re.search("(\d+)%\s.*", nextline) if progress: @@ -356,7 +356,7 @@ class WorkerThread(threading.Thread): return file_path + format_new_ext else: error_message = format_new_ext.upper() + ' format not found on disk' - logger.info("ebook converter failed with error while converting book") + log.info("ebook converter failed with error while converting book") if not error_message: error_message = 'Ebook converter failed with unknown error' self._handleError(error_message) @@ -460,7 +460,7 @@ class WorkerThread(threading.Thread): self.asyncSMTP = email(obj['settings']["mail_server"], obj['settings']["mail_port"], timeout) # link to logginglevel - if logger.is_debug_enabled('general'): + if logger.is_debug_enabled(): self.asyncSMTP.set_debuglevel(1) if use_ssl == 1: self.asyncSMTP.starttls() @@ -502,7 +502,7 @@ class WorkerThread(threading.Thread): return retVal def _handleError(self, error_message): - logger.error(error_message) + log.error(error_message) self.UIqueue[self.current]['stat'] = STAT_FAIL self.UIqueue[self.current]['progress'] = "100 %" self.UIqueue[self.current]['runtime'] = self._formatRuntime(