CodeMirror/manuskript
1
0
Fork 0
mirror of https://github.com/olivierkes/manuskript.git synced 2024-05-02 20:12:24 +12:00
Code Issues Projects Releases Wiki Activity

Added logging & proper argument parsing.

Browse source 
Sometimes you want to do just one thing, and in the process of
implementing that one thing, you implement several others. This is one
of those types of commits.

Implementing the argparse library is for the sake of controlling the
logging behaviour as well as other future I have yet to implement.

It has all the standard goodies you'd expect, and I have also ported
over the existing commandline arguments. (They may need a bit of polish
still, but there is no regression compared to before, only improvement.)

The logger is because it really needed to happen for numerous reasons.

It still logs to the terminal, but by default it only does so for
messages classified WARNING and above. These are the things we actively
want users to see. But if this is not good enough, adding the --verbose
flag will increasingly show more (-v shows INFO level and -vv also shows
the DEBUG messages) so that us coders don't have to miss anything in the
most convenient location.

It also logs to a file with the very original filename manuskript.log. I
may have to add commandline and/or settings arguments to improve that at
some point in the future, but there distractions are endless.

The log file contains timestamps and module information for easy
interpretation that are not present on the terminal, and it contains all
messages classified DEBUG and up. Ideally users will just be able to
attach it to an issue(*) to deliver us all the information we need to
help them with their inquiry.

Last but not least, the other reason I needed logging implemented is
that Qt has its own logging framework, and I needed to figure out how to
siphon out the data and make it shut up. But there was no point in doing
that as long as our own logging facilities were lacking...

(*) I have yet to convert all existing print statements over to the new
system, but that is probably going to be the next commit. This one has
enough change in it already.
This commit is contained in:
Jan Wester 2019-10-14 03:43:17 +02:00
parent b41fb00b0d
commit 8884bac0ed
3 changed files with 157 additions and 13 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

106
manuskript/logging.py Normal file
View file

@ -0,0 +1,106 @@
# -*- coding: utf-8 -*-
# While all logging should be done through the facilities offered by the
# standard python `logging` module, this module will take care of specific
# manuskript needs to keep it separate from the rest of the logic.
from manuskript.functions import writablePath
import os
import logging
LOGFORMAT_CONSOLE = "%(levelname)s> %(message)s"
LOGFORMAT_FILE = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
logger = logging.getLogger(__name__)
def setUp(console_level=logging.WARN):
"""Sets up a convenient environment for logging.
To console: >WARNING, plain. (Only the essence.)"""
# The root_logger should merely trigger on warnings since it is the final
# stop after all categories we really care about didn't match.
root_logger = logging.getLogger()
root_logger.setLevel(logging.WARN)
# The manuskript_logger is what all of our own code will come by.
# Obviously, we care greatly about logging every single message.
manuskript_logger = logging.getLogger("manuskript")
manuskript_logger.setLevel(logging.DEBUG)
# The qt_logger sees all the Qt nonsense when it breaks.
# We don't really want to know... but we have to know.
qt_logger = logging.getLogger("qt")
qt_logger.setLevel(logging.DEBUG)
# Send logs of WARNING+ to STDERR for higher visibility.
ch = logging.StreamHandler()
ch.setLevel(console_level)
ch.setFormatter(logging.Formatter(LOGFORMAT_CONSOLE))
root_logger.addHandler(ch)
logger.debug("Logging to STDERR.")
def logToFile(file_level=logging.DEBUG, logfile=None):
"""Sets up the FileHandler that logs to a file.
This is being done separately due to relying on QApplication being properly
configured; without it we cannot detect the proper location for the log file.
To log file: >DEBUG, timestamped. (All the details.)"""
if logfile is None:
logfile = os.path.join(writablePath(), "manuskript.log")
# Log with extreme prejudice; everything goes to the log file.
# Because Qt gave me a megabyte-sized logfile while testing, it
# makes sense that the default behaviour of appending to existing
# log files may not be in our users best interest for the time
# being. (Unfortunately.)
try:
fh = logging.FileHandler(logfile, mode='w')
fh.setLevel(file_level)
fh.setFormatter(logging.Formatter(LOGFORMAT_FILE))
root_logger = logging.getLogger()
root_logger.addHandler(fh)
# Use INFO level to make it easier to find for users.
logger.info("Logging to file: %s", logfile)
except Exception as ex:
logger.warning("Cannot log to file '%s'. Reason: %s", logfile, ex)
# Qt has its own logging facility that we would like to integrate into our own.
# See: http://thispageintentionally.blogspot.com/2014/03/trapping-qt-log-messages.html
from PyQt5.QtCore import qInstallMessageHandler, QLibraryInfo, QMessageLogContext
from PyQt5.Qt import QtMsgType
def qtMessageHandler(msg_type, msg_log_context, msg_string):
"""Forwards Qt messages to Python logging system."""
# Convert Qt msg type to logging level
log_level = [logging.DEBUG,
logging.WARNING,
logging.ERROR,
logging.FATAL] [ int(msg_type) ]
qtcl = logging.getLogger(msg_log_context.category or "qt.???")
# Some information may not be available unless using a PyQt debug build.
# See: https://www.riverbankcomputing.com/static/Docs/PyQt5/api/qtcore/qmessagelogcontext.html
if QLibraryInfo.isDebugBuild():
qtcl.log(logging.DEBUG,
' @ {0} : {1}'.format((msg_log_context.file or "<unknown source file>"), msg_log_context.line)
)
qtcl.log(logging.DEBUG,
' ! {0}'.format((msg_log_context.function or "<unknown function>"))
)
qtcl.log(log_level, msg_string)
def integrateQtLogging():
"""Integrates Qt logging facilities to be a part of our own."""
# Note: the qtlogger is initialized in setUp() because it fits in
# nicely with the initialization of the other loggers over there.
# I also feel a lot safer this way. Qt is a curse that just keeps
# on giving, even when it isn't actually at fault. I hate you, Qt.
qInstallMessageHandler(qtMessageHandler)

61
manuskript/main.py
View file

@ -6,6 +6,7 @@ import platform
import sys
import signal
import manuskript.logging
import manuskript.ui.views.webView
from PyQt5.QtCore import QLocale, QTranslator, QSettings, Qt
from PyQt5.QtGui import QIcon, QColor, QPalette
@ -16,15 +17,24 @@ from manuskript.version import getVersion
faulthandler.enable()
import logging
logger = logging.getLogger(__name__)
def prepare(tests=False):
def prepare(arguments, tests=False):
app = QApplication(sys.argv)
app.setOrganizationName("manuskript" + ("_tests" if tests else ""))
app.setOrganizationDomain("www.theologeek.ch")
app.setApplicationName("manuskript" + ("_tests" if tests else ""))
app.setApplicationVersion(getVersion())
print("Running manuskript version {}.".format(getVersion()))
# Beginning logging to a file. This cannot be done earlier due to the
# default location of the log file being dependent on QApplication.
manuskript.logging.logToFile(logfile=arguments.logfile)
# Handle all sorts of Qt logging messages in Python.
manuskript.logging.integrateQtLogging()
logger.info("Running manuskript version {}.".format(getVersion()))
icon = QIcon()
for i in [16, 32, 64, 128, 256, 512]:
icon.addFile(appPath("icons/Manuskript/icon-{}px.png".format(i)))
@ -47,7 +57,7 @@ def prepare(tests=False):
"""Tries to load and activate a given translation for use."""
if appTranslator.load(translation, appPath("i18n")):
app.installTranslator(appTranslator)
print("Loaded translation: {}".format(translation))
logger.info("Loaded translation: {}".format(translation))
# Note: QTranslator.load() does some fancy heuristics where it simplifies
# the given locale until it is 'close enough' if the given filename does
# not work out. For example, if given 'i18n/manuskript_en_US.qm', it tries:
@ -62,7 +72,7 @@ def prepare(tests=False):
# filenames when you observe strange behaviour with the loaded translations.
return True
else:
print("No translation found or loaded. ({})".format(translation))
logger.info("No translation found or loaded. ({})".format(translation))
return False
def activateTranslation(translation, source):
@ -85,7 +95,7 @@ def prepare(tests=False):
break
if using_builtin_translation:
print("Using the builtin translation.")
logger.info("Using the builtin translation. (U.S. English)")
# Load application translation
translation = ""
@ -99,7 +109,7 @@ def prepare(tests=False):
translation = QLocale().uiLanguages()
source = "available ui languages"
print("Preferred translation: {} (based on {})".format(("builtin" if translation == "" else translation), source))
logger.info("Preferred translation: {} (based on {})".format(("builtin" if translation == "" else translation), source))
activateTranslation(translation, source)
def respectSystemDarkThemeSetting():
@ -164,15 +174,16 @@ def prepare(tests=False):
MW._defaultCursorFlashTime = qApp.cursorFlashTime()
# Command line project
if len(sys.argv) > 1 and sys.argv[1][-4:] == ".msk":
#if len(sys.argv) > 1 and sys.argv[1][-4:] == ".msk":
if arguments.filename is not None and arguments.filename[-4:] == ".msk":
#TODO: integrate better with argparsing.
if os.path.exists(sys.argv[1]):
path = os.path.abspath(sys.argv[1])
MW._autoLoadProject = path
return app, MW
def launch(app, MW=None):
def launch(arguments, app, MW = None):
if MW == None:
from manuskript.functions import mainWindow
MW = mainWindow()
@ -184,7 +195,7 @@ def launch(app, MW=None):
# Code reference :
# https://github.com/ipython/ipykernel/blob/master/examples/embedding/ipkernel_qtapp.py
# https://github.com/ipython/ipykernel/blob/master/examples/embedding/internal_ipkernel.py
if len(sys.argv) > 1 and sys.argv[-1] == "--console":
if arguments.console:
try:
from IPython.lib.kernel import connect_qtconsole
from ipykernel.kernelapp import IPKernelApp
@ -241,18 +252,44 @@ def setup_signal_handlers(MW):
signal.signal(signal.SIGTERM, sigint_handler("SIGTERM", MW))
def process_commandline(argv):
import argparse
parser = argparse.ArgumentParser(description="Run the manuskript application.")
parser.add_argument("--console", help="open the IPython Jupyter QT Console as a debugging aid",
action="store_true")
parser.add_argument("-v", "--verbose", action="count", default=1, help="lower the threshold for messages logged to the terminal")
parser.add_argument("-L", "--logfile", default=None, help="override the default log file location")
parser.add_argument("filename", nargs="?", metavar="FILENAME", help="the manuskript project (.msk) to open")
args = parser.parse_args(args=argv)
# Verbosity logic, see: https://gist.github.com/ms5/9f6df9c42a5f5435be0e
#args.verbose = 70 - (10*args.verbose) if args.verbose > 0 else 0
# Users cannot report what they do not notice: show CRITICAL, ERROR and WARNING always.
# Note that the default is set to 1, so account for that.
args.verbose = 40 - (10*args.verbose) if args.verbose > 0 else 0
return args
def run():
"""
Run separates prepare and launch for two reasons:
1. I've read somewhere it helps with potential segfault (see comment below)
2. So that prepare can be used in tests, without running the whole thing
"""
# Parse command-line arguments.
arguments = process_commandline(sys.argv)
# Initialize logging. (Does not include Qt integration yet.)
manuskript.logging.setUp(console_level=arguments.verbose)
# Need to return and keep `app` otherwise it gets deleted.
app, MW = prepare()
app, MW = prepare(arguments)
setup_signal_handlers(MW)
# Separating launch to avoid segfault, so it seem.
# Cf. http://stackoverflow.com/questions/12433491/is-this-pyqt-4-python-bug-or-wrongly-behaving-code
launch(app, MW)
launch(arguments, app, MW)
if __name__ == "__main__":

3
manuskript/tests/__init__.py
View file

@ -13,7 +13,8 @@ QApplication([])
# Create app and mainWindow
from manuskript import main
app, MW = main.prepare(tests=True)
arguments = main.process_commandline([])
app, MW = main.prepare(arguments, tests=True)
# FIXME: Again, don't know why, but when closing a project and then reopening
# one, we get a `TypeError: connection is not unique` in MainWindow: