@@ -2584,3 +2584,399 @@ In this case, the message #5 printed to ``stdout`` doesn't appear, as expected.
25842584Of course, the approach described here can be generalised, for example to attach
25852585logging filters temporarily. Note that the above code works in Python 2 as well
25862586as Python 3.
2587+
2588+
2589+ .. _starter-template :
2590+
2591+ A CLI application starter template
2592+ ----------------------------------
2593+
2594+ Here's an example which shows how you can:
2595+
2596+ * Use a logging level based on command-line arguments
2597+ * Dispatch to multiple subcommands in separate files, all logging at the same
2598+ level in a consistent way
2599+ * Make use of simple, minimal configuration
2600+
2601+ Suppose we have a command-line application whose job is to stop, start or
2602+ restart some services. This could be organised for the purposes of illustration
2603+ as a file ``app.py `` that is the main script for the application, with individual
2604+ commands implemented in ``start.py ``, ``stop.py `` and ``restart.py ``. Suppose
2605+ further that we want to control the verbosity of the application via a
2606+ command-line argument, defaulting to ``logging.INFO ``. Here's one way that
2607+ ``app.py `` could be written::
2608+
2609+ import argparse
2610+ import importlib
2611+ import logging
2612+ import os
2613+ import sys
2614+
2615+ def main(args=None):
2616+ scriptname = os.path.basename(__file__)
2617+ parser = argparse.ArgumentParser(scriptname)
2618+ levels = ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
2619+ parser.add_argument('--log-level', default='INFO', choices=levels)
2620+ subparsers = parser.add_subparsers(dest='command',
2621+ help='Available commands:')
2622+ start_cmd = subparsers.add_parser('start', help='Start a service')
2623+ start_cmd.add_argument('name', metavar='NAME',
2624+ help='Name of service to start')
2625+ stop_cmd = subparsers.add_parser('stop',
2626+ help='Stop one or more services')
2627+ stop_cmd.add_argument('names', metavar='NAME', nargs='+',
2628+ help='Name of service to stop')
2629+ restart_cmd = subparsers.add_parser('restart',
2630+ help='Restart one or more services')
2631+ restart_cmd.add_argument('names', metavar='NAME', nargs='+',
2632+ help='Name of service to restart')
2633+ options = parser.parse_args()
2634+ # the code to dispatch commands could all be in this file. For the purposes
2635+ # of illustration only, we implement each command in a separate module.
2636+ try:
2637+ mod = importlib.import_module(options.command)
2638+ cmd = getattr(mod, 'command')
2639+ except (ImportError, AttributeError):
2640+ print('Unable to find the code for command \'%s\'' % options.command)
2641+ return 1
2642+ # Could get fancy here and load configuration from file or dictionary
2643+ logging.basicConfig(level=options.log_level,
2644+ format='%(levelname)s %(name)s %(message)s')
2645+ cmd(options)
2646+
2647+ if __name__ == '__main__':
2648+ sys.exit(main())
2649+
2650+ And the ``start ``, ``stop `` and ``restart `` commands can be implemented in
2651+ separate modules, like so for starting::
2652+
2653+ # start.py
2654+ import logging
2655+
2656+ logger = logging.getLogger(__name__)
2657+
2658+ def command(options):
2659+ logger.debug('About to start %s', options.name)
2660+ # actually do the command processing here ...
2661+ logger.info('Started the \'%s\' service.', options.name)
2662+
2663+ and thus for stopping::
2664+
2665+ # stop.py
2666+ import logging
2667+
2668+ logger = logging.getLogger(__name__)
2669+
2670+ def command(options):
2671+ n = len(options.names)
2672+ if n == 1:
2673+ plural = ''
2674+ services = '\'%s\'' % options.names[0]
2675+ else:
2676+ plural = 's'
2677+ services = ', '.join('\'%s\'' % name for name in options.names)
2678+ i = services.rfind(', ')
2679+ services = services[:i] + ' and ' + services[i + 2:]
2680+ logger.debug('About to stop %s', services)
2681+ # actually do the command processing here ...
2682+ logger.info('Stopped the %s service%s.', services, plural)
2683+
2684+ and similarly for restarting::
2685+
2686+ # restart.py
2687+ import logging
2688+
2689+ logger = logging.getLogger(__name__)
2690+
2691+ def command(options):
2692+ n = len(options.names)
2693+ if n == 1:
2694+ plural = ''
2695+ services = '\'%s\'' % options.names[0]
2696+ else:
2697+ plural = 's'
2698+ services = ', '.join('\'%s\'' % name for name in options.names)
2699+ i = services.rfind(', ')
2700+ services = services[:i] + ' and ' + services[i + 2:]
2701+ logger.debug('About to restart %s', services)
2702+ # actually do the command processing here ...
2703+ logger.info('Restarted the %s service%s.', services, plural)
2704+
2705+ If we run this application with the default log level, we get output like this:
2706+
2707+ .. code-block :: shell-session
2708+
2709+ $ python app.py start foo
2710+ INFO start Started the 'foo' service.
2711+
2712+ $ python app.py stop foo bar
2713+ INFO stop Stopped the 'foo' and 'bar' services.
2714+
2715+ $ python app.py restart foo bar baz
2716+ INFO restart Restarted the 'foo', 'bar' and 'baz' services.
2717+
2718+ The first word is the logging level, and the second word is the module or
2719+ package name of the place where the event was logged.
2720+
2721+ If we change the logging level, then we can change the information sent to the
2722+ log. For example, if we want more information:
2723+
2724+ .. code-block :: shell-session
2725+
2726+ $ python app.py --log-level DEBUG start foo
2727+ DEBUG start About to start foo
2728+ INFO start Started the 'foo' service.
2729+
2730+ $ python app.py --log-level DEBUG stop foo bar
2731+ DEBUG stop About to stop 'foo' and 'bar'
2732+ INFO stop Stopped the 'foo' and 'bar' services.
2733+
2734+ $ python app.py --log-level DEBUG restart foo bar baz
2735+ DEBUG restart About to restart 'foo', 'bar' and 'baz'
2736+ INFO restart Restarted the 'foo', 'bar' and 'baz' services.
2737+
2738+ And if we want less:
2739+
2740+ .. code-block :: shell-session
2741+
2742+ $ python app.py --log-level WARNING start foo
2743+ $ python app.py --log-level WARNING stop foo bar
2744+ $ python app.py --log-level WARNING restart foo bar baz
2745+
2746+ In this case, the commands don't print anything to the console, since nothing
2747+ at ``WARNING `` level or above is logged by them.
2748+
2749+ .. _qt-gui :
2750+
2751+ A Qt GUI for logging
2752+ --------------------
2753+
2754+ A question that comes up from time to time is about how to log to a GUI
2755+ application. The `Qt <https://www.qt.io/ >`_ framework is a popular
2756+ cross-platform UI framework with Python bindings using `PySide2
2757+ <https://pypi.org/project/PySide2/> `_ or `PyQt5
2758+ <https://pypi.org/project/PyQt5/> `_ libraries.
2759+
2760+ The following example shows how to log to a Qt GUI. This introduces a simple
2761+ ``QtHandler `` class which takes a callable, which should be a slot in the main
2762+ thread that does GUI updates. A worker thread is also created to show how you
2763+ can log to the GUI from both the UI itself (via a button for manual logging)
2764+ as well as a worker thread doing work in the background (here, just logging
2765+ messages at random levels with random short delays in between).
2766+
2767+ The worker thread is implemented using Qt's ``QThread `` class rather than the
2768+ :mod: `threading ` module, as there are circumstances where one has to use
2769+ ``QThread ``, which offers better integration with other ``Qt `` components.
2770+
2771+ The code should work with recent releases of either ``PySide2 `` or ``PyQt5 ``.
2772+ You should be able to adapt the approach to earlier versions of Qt. Please
2773+ refer to the comments in the code snippet for more detailed information.
2774+
2775+ .. code-block :: python3
2776+
2777+ import datetime
2778+ import logging
2779+ import random
2780+ import sys
2781+ import time
2782+
2783+ # Deal with minor differences between PySide2 and PyQt5
2784+ try:
2785+ from PySide2 import QtCore, QtGui, QtWidgets
2786+ Signal = QtCore.Signal
2787+ Slot = QtCore.Slot
2788+ except ImportError:
2789+ from PyQt5 import QtCore, QtGui, QtWidgets
2790+ Signal = QtCore.pyqtSignal
2791+ Slot = QtCore.pyqtSlot
2792+
2793+
2794+ logger = logging.getLogger(__name__)
2795+
2796+
2797+ #
2798+ # Signals need to be contained in a QObject or subclass in order to be correctly
2799+ # initialized.
2800+ #
2801+ class Signaller(QtCore.QObject):
2802+ signal = Signal(str, logging.LogRecord)
2803+
2804+ #
2805+ # Output to a Qt GUI is only supposed to happen on the main thread. So, this
2806+ # handler is designed to take a slot function which is set up to run in the main
2807+ # thread. In this example, the function takes a string argument which is a
2808+ # formatted log message, and the log record which generated it. The formatted
2809+ # string is just a convenience - you could format a string for output any way
2810+ # you like in the slot function itself.
2811+ #
2812+ # You specify the slot function to do whatever GUI updates you want. The handler
2813+ # doesn't know or care about specific UI elements.
2814+ #
2815+ class QtHandler(logging.Handler):
2816+ def __init__(self, slotfunc, *args, **kwargs):
2817+ super(QtHandler, self).__init__(*args, **kwargs)
2818+ self.signaller = Signaller()
2819+ self.signaller.signal.connect(slotfunc)
2820+
2821+ def emit(self, record):
2822+ s = self.format(record)
2823+ self.signaller.signal.emit(s, record)
2824+
2825+ #
2826+ # This example uses QThreads, which means that the threads at the Python level
2827+ # are named something like "Dummy-1". The function below gets the Qt name of the
2828+ # current thread.
2829+ #
2830+ def ctname():
2831+ return QtCore.QThread.currentThread().objectName()
2832+
2833+
2834+ #
2835+ # Used to generate random levels for logging.
2836+ #
2837+ LEVELS = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,
2838+ logging.CRITICAL)
2839+
2840+ #
2841+ # This worker class represents work that is done in a thread separate to the
2842+ # main thread. The way the thread is kicked off to do work is via a button press
2843+ # that connects to a slot in the worker.
2844+ #
2845+ # Because the default threadName value in the LogRecord isn't much use, we add
2846+ # a qThreadName which contains the QThread name as computed above, and pass that
2847+ # value in an "extra" dictionary which is used to update the LogRecord with the
2848+ # QThread name.
2849+ #
2850+ # This example worker just outputs messages sequentially, interspersed with
2851+ # random delays of the order of a few seconds.
2852+ #
2853+ class Worker(QtCore.QObject):
2854+ @Slot()
2855+ def start(self):
2856+ extra = {'qThreadName': ctname() }
2857+ logger.debug('Started work', extra=extra)
2858+ i = 1
2859+ # Let the thread run until interrupted. This allows reasonably clean
2860+ # thread termination.
2861+ while not QtCore.QThread.currentThread().isInterruptionRequested():
2862+ delay = 0.5 + random.random() * 2
2863+ time.sleep(delay)
2864+ level = random.choice(LEVELS)
2865+ logger.log(level, 'Message after delay of %3.1f: %d', delay, i, extra=extra)
2866+ i += 1
2867+
2868+ #
2869+ # Implement a simple UI for this cookbook example. This contains:
2870+ #
2871+ # * A read-only text edit window which holds formatted log messages
2872+ # * A button to start work and log stuff in a separate thread
2873+ # * A button to log something from the main thread
2874+ # * A button to clear the log window
2875+ #
2876+ class Window(QtWidgets.QWidget):
2877+
2878+ COLORS = {
2879+ logging.DEBUG: 'black',
2880+ logging.INFO: 'blue',
2881+ logging.WARNING: 'orange',
2882+ logging.ERROR: 'red',
2883+ logging.CRITICAL: 'purple',
2884+ }
2885+
2886+ def __init__(self, app):
2887+ super(Window, self).__init__()
2888+ self.app = app
2889+ self.textedit = te = QtWidgets.QPlainTextEdit(self)
2890+ # Set whatever the default monospace font is for the platform
2891+ f = QtGui.QFont('nosuchfont')
2892+ f.setStyleHint(f.Monospace)
2893+ te.setFont(f)
2894+ te.setReadOnly(True)
2895+ PB = QtWidgets.QPushButton
2896+ self.work_button = PB('Start background work', self)
2897+ self.log_button = PB('Log a message at a random level', self)
2898+ self.clear_button = PB('Clear log window', self)
2899+ self.handler = h = QtHandler(self.update_status)
2900+ # Remember to use qThreadName rather than threadName in the format string.
2901+ fs = '%(asctime)s %(qThreadName)-12s %(levelname)-8s %(message)s'
2902+ formatter = logging.Formatter(fs)
2903+ h.setFormatter(formatter)
2904+ logger.addHandler(h)
2905+ # Set up to terminate the QThread when we exit
2906+ app.aboutToQuit.connect(self.force_quit)
2907+
2908+ # Lay out all the widgets
2909+ layout = QtWidgets.QVBoxLayout(self)
2910+ layout.addWidget(te)
2911+ layout.addWidget(self.work_button)
2912+ layout.addWidget(self.log_button)
2913+ layout.addWidget(self.clear_button)
2914+ self.setFixedSize(900, 400)
2915+
2916+ # Connect the non-worker slots and signals
2917+ self.log_button.clicked.connect(self.manual_update)
2918+ self.clear_button.clicked.connect(self.clear_display)
2919+
2920+ # Start a new worker thread and connect the slots for the worker
2921+ self.start_thread()
2922+ self.work_button.clicked.connect(self.worker.start)
2923+ # Once started, the button should be disabled
2924+ self.work_button.clicked.connect(lambda : self.work_button.setEnabled(False))
2925+
2926+ def start_thread(self):
2927+ self.worker = Worker()
2928+ self.worker_thread = QtCore.QThread()
2929+ self.worker.setObjectName('Worker')
2930+ self.worker_thread.setObjectName('WorkerThread') # for qThreadName
2931+ self.worker.moveToThread(self.worker_thread)
2932+ # This will start an event loop in the worker thread
2933+ self.worker_thread.start()
2934+
2935+ def kill_thread(self):
2936+ # Just tell the worker to stop, then tell it to quit and wait for that
2937+ # to happen
2938+ self.worker_thread.requestInterruption()
2939+ if self.worker_thread.isRunning():
2940+ self.worker_thread.quit()
2941+ self.worker_thread.wait()
2942+ else:
2943+ print('worker has already exited.')
2944+
2945+ def force_quit(self):
2946+ # For use when the window is closed
2947+ if self.worker_thread.isRunning():
2948+ self.kill_thread()
2949+
2950+ # The functions below update the UI and run in the main thread because
2951+ # that's where the slots are set up
2952+
2953+ @Slot(str, logging.LogRecord)
2954+ def update_status(self, status, record):
2955+ color = self.COLORS.get(record.levelno, 'black')
2956+ s = '<pre><font color="%s">%s</font></pre>' % (color, status)
2957+ self.textedit.appendHtml(s)
2958+
2959+ @Slot()
2960+ def manual_update(self):
2961+ # This function uses the formatted message passed in, but also uses
2962+ # information from the record to format the message in an appropriate
2963+ # color according to its severity (level).
2964+ level = random.choice(LEVELS)
2965+ extra = {'qThreadName': ctname() }
2966+ logger.log(level, 'Manually logged!', extra=extra)
2967+
2968+ @Slot()
2969+ def clear_display(self):
2970+ self.textedit.clear()
2971+
2972+
2973+ def main():
2974+ QtCore.QThread.currentThread().setObjectName('MainThread')
2975+ logging.getLogger().setLevel(logging.DEBUG)
2976+ app = QtWidgets.QApplication(sys.argv)
2977+ example = Window(app)
2978+ example.show()
2979+ sys.exit(app.exec_())
2980+
2981+ if __name__=='__main__':
2982+ main()
0 commit comments