Revert logging functions

Fix access logger for tornado
pull/945/head
Ozzieisaacs 5 years ago
parent 8e4539cf8e
commit 26949970d8

@ -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)

@ -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:

@ -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, "")

@ -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

@ -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)

@ -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 ''

@ -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)

@ -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')

@ -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')

@ -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

@ -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'))

@ -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)

@ -33,7 +33,7 @@ from .web import render_title_template
shelf = Blueprint('shelf', __name__)
# log = logger.create()
log = logger.create()
@shelf.route("/shelf/add/<int:shelf_id>/<int:book_id>")
@ -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/<int:shelf_id>")
@ -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),

@ -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):

@ -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:

@ -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

@ -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:

@ -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(

Loading…
Cancel
Save