Rewrite the whole thing as a Formatter

Having a complete `Logger` class for this purpose is a bit of an overkill.

docs/conf.py

@@ -60,9 +60,9 @@ author = 'Gergely Polonkai'
 # built documents.
 #
 # The short X.Y version.
-version = '0.1'
+version = '1.0'
 # The full version, including alpha/beta/rc tags.
-release = '0.1.1'
+release = '1.0.0'
 
 # The language for content autogenerated by Sphinx. Refer to documentation
 # for a list of supported languages.

flask_logging_extras/__init__.py

@@ -34,15 +34,15 @@ import logging
 
 from flask import has_request_context, request, current_app, has_app_context
 
-__version_info__ = ('0', '0', '1')
+__version_info__ = ('1', '0', '0')
 __version__ = '.'.join(__version_info__)
 __author__ = 'Gergely Polonkai'
 __license__ = 'MIT'
-__copyright__ = '(c) 2015 GT2'
+__copyright__ = '(c) 2015-2018 Benchmarked.games'
 
-class FlaskExtraLogger(logging.getLoggerClass()):
+
-    """
+class FlaskExtraLoggerFormatter(logging.Formatter):
-    A logger class that is capable of adding extra keywords to log
+    """A log formatter class that is capable of adding extra keywords to log
     formatters and logging the blueprint name
 
     Usage:
@@ -50,205 +50,92 @@ class FlaskExtraLogger(logging.getLoggerClass()):
     .. code-block:: python
 
        import logging
+       from logging.config import dictConfig
 
-       from flask_logging_extras import register_logger_class
+       dictConfig({
-
+           'formatters': {
-       # This must be done before the app is initialized!
+               'extras': {
-       register_logger_class(cls=FlaskExtraLogger)
+                   'format': '[%(asctime)s] [%(levelname)s] [%(category)s] [%(blueprint)s] %(message)s',
+               },
+           },
+           'handlers': {
+               'extras_handler': {
+                   'class': 'logging.FileHandler',
+                   'args': ('app.log', 'a'),
+                   'formatter': 'extras',
+                   'level': 'INFO',
+               },
+           },
+           'loggers': {
+               'my_app': {
+                   'handlers': ['extras_handler'],
+               }
+           },
+       })
 
        app = Flask(__name__)
        app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = {'category': '<unset>'}
        app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = ('blueprint',
                                                        '<APP>',
                                                        '<NOT REQUEST>')
-       app.logger.init_app()
 
        bp = Blueprint('my_blueprint', __name__)
        app.register_blueprint(bp)
 
-       formatter = logging.Formatter(
+       logger = logging.getLogger('my_app')
-           '[%(asctime)s] [%(levelname)s] [%(category)s] %(message)s')
-       handler = logging.FileHandler('app.log', mode='a')
-       handler.setFormatter(formatter)
-       handler.setLevel(logging.INFO)
-
-       app.logger.addHandler(handler)
-
-       app.logger.info('The message', category='my category')
 
        # This will produce something like this in app.log:
-       # [2017-01-16 08:44:48.944] [INFO] [my category] The message
+       # [2018-05-02 12:44:48.944] [INFO] [my category] [<NOT REQUEST>] The message
+       logger.info('The message', extra=dict(category='my category'))
 
-       formatter = logging.Formatter('[%(blueprint)s] %(message)s')
+       @app.route('/1')
-       handler = logging.FileHandler('other.log', mode='a')
-       handler.setFormatter(formatter)
-       handler.setLevel(logging.INFO)
-
-       app.logger.addHandler(handler)
-
-       @app.route('/1/')
        def route_1():
-           # This will produce this log message:
+           # This will produce a log message like this:
-           # [<APP>] Message
+           # [2018-05-02 12:44:48.944] [INFO] [<unset>] [<APP>] Message
-           current_app.logger.info('Message')
+           logger.info('Message')
 
            return ''
 
        @bp.route('/2')
        def route_2():
-           # This will produce this log message:
+           # This will produce a log message like this:
-           # [my blueprint] Message
+           # [2018-05-02 12:44:48.944] [INFO] [<unset>] [my_blueprint] Message
-           current_app.logger.info('Message')
+           logger.info('Message')
 
            return ''
 
-       # This will produce this log message:
+       # This will produce a log message like this:
-       [<NOT REQUEST>] Message
+       # [2018-05-02 12:44:48.944] [INFO] [<unset>] [<NOT REQUEST>] Message
-       app.logger.info('Message')
+       logger.info('Message')
     """
 
-    _RESERVED_KEYWORDS = ('exc_info', 'extra', 'stack_info')
+    def _collect_keywords(self, record):
-
+        """Collect all valid keywords and add them to the log record if not present
-    def __init__(self, *args, **kwargs):
-        if 'app' in kwargs:
-            if kwargs['app'] is not None:
-                raise TypeError(
-                    "Cannot initialise {classname} with an app.  See the"
-                    "documentation of Flask-Logging-Extras for more info."
-                    .format(classname=self.__class__.__name__))
-            else:
-                # If app is None, treat it as if it wasn’t there
-                del(kwargs['app'])
-
-        self.app = None
-        self._valid_keywords = {}
-        self._blueprint_var = None
-        self._blueprint_app = None
-        self._blueprint_norequest = None
-
-        super(FlaskExtraLogger, self).__init__(*args, **kwargs)
-
-        if hasattr(self.__class__, '__default_config__'):
-            self.config = self.__class__.__default_config__
-            self.init_from_config()
-
-    def _log(self, *args, **kwargs):
-        if has_app_context() and self.app is None:
-            self.init_app(current_app)
-
-        if 'extra' not in kwargs:
-            kwargs['extra'] = {}
-
-        # If we were asked to log the blueprint name, add it to the extra list
-        if self._blueprint_var is not None:
-            if has_request_context():
-                kwargs['extra'][self._blueprint_var] = request.blueprint or self._blueprint_app
-            else:
-                kwargs['extra'][self._blueprint_var] = self._blueprint_norequest
-
-        for kw in self._valid_keywords:
-            if kw in kwargs:
-                kwargs['extra'][kw] = kwargs[kw]
-                del(kwargs[kw])
-            else:
-                kwargs['extra'][kw] = self._valid_keywords[kw]
-
-        super(FlaskExtraLogger, self)._log(*args, **kwargs)
-
-    def _check_reserved_word(self, word):
-        if word in self._RESERVED_KEYWORDS:
-            raise ValueError(
-                '"{keyword}" cannot be used as an extra keyword, as it is '
-                'reserved for internal use.'
-                .format(keyword=word))
-
-    def init_from_config(self):
-        """Intialize the logger class from a Flask config dict
-
-        The class reads its necessary configuration from the config provided.
-
-        If the application doesn’t call this, or doesn’t have the `FLASK_LOGGING_EXTRAS_KEYWORDS`
-        in its config, no extra functionality will be added.
-
-        :raises ValueError: if the app tries to register a keyword that is
-                             reserved for internal use
-
         """
 
-        if not isinstance(self.config, dict):
+        # We assume we do have an active app context here
-            self.config = {
+        defaults = current_app.config.get('FLASK_LOGGING_EXTRAS_KEYWORDS', {})
-                'FLASK_LOGGING_EXTRAS_KEYWORDS': getattr(self.config, 'FLASK_LOGGING_EXTRAS_KEYWORDS', {}),
-                'FLASK_LOGGING_EXTRAS_BLUEPRINT': getattr(self.config, 'FLASK_LOGGING_EXTRAS_BLUEPRINT', (None, '<app>', '<not a request>',)),
-            }
 
-        self.config.setdefault('FLASK_LOGGING_EXTRAS_KEYWORDS', {})
+        for keyword, default in defaults.items():
-        self.config.setdefault('FLASK_LOGGING_EXTRAS_BLUEPRINT',
+            if keyword not in record.__dict__:
-                               (None, '<app>', '<not a request>'))
+                setattr(record, keyword, default)
 
-        for kw in self.config['FLASK_LOGGING_EXTRAS_KEYWORDS']:
+    def format(self, record):
-            self._check_reserved_word(kw)
+        bp_var, bp_app, bp_noreq = ('blueprint', '<app>', '<not a request>')
+        blueprint = None
 
-        self._check_reserved_word(
+        if has_app_context():
-            self.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'][0])
+            self._collect_keywords(record)
 
-        self._valid_keywords = self.config['FLASK_LOGGING_EXTRAS_KEYWORDS']
+            bp_var, bp_app, bp_noreq = current_app.config.get('FLASK_LOGGING_EXTRAS_BLUEPRINT',
-        (
+                                                              (bp_var, bp_app, bp_noreq))
-            self._blueprint_var,
-            self._blueprint_app,
-            self._blueprint_norequest,
-        ) = self.config['FLASK_LOGGING_EXTRAS_BLUEPRINT']
 
-    def init_app(self, app):
+            if bp_var and has_request_context():
-        """
+                blueprint = request.blueprint or bp_app
-        Intialize the logger class with a Flask application
 
-        The class reads its necessary configuration from the config of this
+        if bp_var and bp_var not in record.__dict__:
-        application.
+            blueprint = blueprint or bp_noreq
 
-        If the application doesn’t call this, or doesn’t have the
+            setattr(record, bp_var, blueprint)
-        `FLASK_LOGGING_EXTRAS_KEYWORDS` in its config, no extra
-        functionality will be added.
 
-        :param app: a Flask application
+        return super(FlaskExtraLoggerFormatter, self).format(record)
-        :type app: Flask
-        :raises ValueError: if the app tries to register a keyword that is
-                             reserved for internal use
-        """
-
-        self.app = app
-        self.config = app.config
-        self.init_from_config()
-
-
-def register_logger_class(cls=FlaskExtraLogger, config=None):
-    """
-    Register a new logger class
-
-    It is effectively a wrapper around `logging.setLoggerClass()`, with an
-    added check to make sure the class can be used as a logger.
-
-    To use the extra features of the logger class in a Flask app, you must
-    call it before the app is instantiated.
-
-    This function returns the logger class that was the default before
-    calling.  This might be useful if you only want to use `cls` in the
-    Flask app object, but not anywhere else in your code.  In this case,
-    simply call `register_logger_class()` again with the return value from
-    the first invocation.
-
-    :param cls: a logger class to register as the default one
-    :type cls: class(logging.Logger)
-    :returns: the old default logger class
-    :rtype: class
-    :raises TypeError: if the class is not a subclass of `logging.Logger`
-    """
-
-    if not issubclass(cls, logging.Logger):
-        raise TypeError(
-            "The logger class must be a subclass of logging.Logger!")
-
-    old_class = logging.getLoggerClass()
-    logging.setLoggerClass(cls)
-    cls.__default_config__ = config
-
-    return old_class

setup.py

@@ -8,7 +8,7 @@ Flask-Logging-Extras provides extra logging functionality for Flask apps.
 from setuptools import setup
 
 setup(name='Flask-Logging-Extras',
-      version='0.2.0',
+      version='1.0.0',
       url='https://github.com/gergelypolonkai/flask-logging-extras',
       license='MIT',
       author='Gergely Polonkai',

tests/test_logger_keywords.py

@@ -1,9 +1,9 @@
 # -*- coding: utf-8 -*-
-"""
+"""Unit tests for Flask-Logging-Extras
-Unit tests for Flask-Logging-Extras
 """
 
 import logging
+from logging.config import dictConfig
 import sys
 from unittest import TestCase
 
@@ -11,203 +11,124 @@ from flask import Flask, Blueprint, current_app
 
 import flask_logging_extras
 
-class ListStream(object):
-    """
-    Primitive stream that stores its input lines in a list
-    """
 
+class ListHandler(logging.StreamHandler):
     def __init__(self, *args, **kwargs):
-        self.lines = []
+        super(ListHandler, self).__init__(*args, **kwargs)
 
-        super(ListStream, self).__init__(*args, **kwargs)
+        self.logs = []
 
-    def write(self, data):
+    def emit(self, record):
-        if len(self.lines) == 0 or self.lines[-1].endswith('\n'):
+        try:
-            self.lines.append(data)
+            msg = self.format(record)
-        else:
+        except (KeyError, IndexError) as exc:
-            self.lines[-1] += data
+            msg = (exc.__class__.__name__, str(exc))
+
+        self.logs.append(msg)
 
 
-class TestingStreamHandler(logging.StreamHandler):
+def configure_loggers(extra_var):
-    def handleError(self, record):
+    dictConfig({
-        exc, exc_msg, trace = sys.exc_info()
+        'version': 1,
+        'disable_existing_loggers': True,
+        'formatters': {
+            'selftest': {
+                'class': 'flask_logging_extras.FlaskExtraLoggerFormatter',
+                'format': '%(message)s %({extra_var})s'.format(extra_var=extra_var),
+            },
+        },
+        'handlers': {
+            'selftest': {
+                'class': 'test_logger_keywords.ListHandler',
+                'formatter': 'selftest',
+            },
+        },
+        'loggers': {
+            'selftest': {
+                'handlers': ['selftest'],
+                'level': 'INFO',
+            },
+        },
+    })
 
-        super(logging.StreamHandler, self).handleError(record)
+    formatter = flask_logging_extras.FlaskExtraLoggerFormatter(
+        fmt='%(message)s %({extra_var})s'.format(extra_var=extra_var))
 
-        raise(exc(exc_msg))
+    logger = logging.getLogger('selftest')
+    handlers = [handler for handler in logger.handlers if isinstance(handler, ListHandler)]
+    handler = handlers[0]
+    # TODO: Why doesn’t this happen automatically in Python 2.7?
+    handler.setFormatter(formatter)
+
+    return logger, handler
 
 
 class LoggerKeywordsTestCase(TestCase):
     def setUp(self):
-        self.original_logger_class = logging.getLoggerClass()
+        self.logger, self.handler = configure_loggers('extra_keyword')
+        self.app = Flask('test_app')
+        self.app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = {
+            'extra_keyword': 'placeholder',
+        }
 
-    def tearDown(self):
+        # Make sure we don’t try to log the current blueprint for this test case
-        logging.setLoggerClass(self.original_logger_class)
+        self.app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = (None, '', '')
 
-    def test_logger_registration(self):
+    def test_keywords_no_app_ctx(self):
-        class NotLoggerClass(object):
+        """With the current formatter, the last log line must be a just the message
-            pass
+        """
 
-        with self.assertRaises(TypeError):
+        self.logger.info('message')
-            flask_logging_extras.register_logger_class(cls=NotLoggerClass)
+        self.assertIn(('KeyError', "'extra_keyword'"), self.handler.logs)
 
-        original_logging_class = logging.getLoggerClass()
+    def test_keywords_app_ctx_assign_value(self):
-
+        """If we don’t register 'extra_keyword' in the app config, we get a
-        old_class = flask_logging_extras.register_logger_class()
-
-        # If no class is specified, FlaskExtraLogger should be registered
-        self.assertEqual(logging.getLoggerClass(),
-                         flask_logging_extras.FlaskExtraLogger)
-        # The return value of this function should be the old default
-        self.assertEqual(original_logging_class, old_class)
-
-        class MyLogger(logging.Logger):
-            pass
-
-        # Calling register_logger_class() with any subclass of
-        # logging.Logger should succeed
-        flask_logging_extras.register_logger_class(cls=MyLogger)
-
-    def test_logger_class(self):
-        # If app is present during __init__, and is not None, we should get
-        # a TypeError
-        with self.assertRaises(TypeError):
-            flask_logging_extras.FlaskExtraLogger('test_logger',
-                                                  app='test value')
-
-        # If app is present, but is None, no exception should be raised
-        flask_logging_extras.FlaskExtraLogger('test_logger', app=None)
-
-    def test_logger_class_init_app(self):
-        logger = flask_logging_extras.FlaskExtraLogger('test')
-        app = Flask('test_app')
-
-        logger.init_app(app)
-
-        self.assertEqual({}, logger._valid_keywords)
-
-        app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = {'exc_info': None}
-
-        with self.assertRaises(ValueError):
-            logger.init_app(app)
-
-        app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = {'my_keyword': '<unset>'}
-
-        logger.init_app(app)
-        self.assertEqual({'my_keyword': '<unset>'}, logger._valid_keywords)
-
-        # Without registration first, app.logger should not be of class
-        # FlaskExtraLogger (even though logger.init_app() succeeded without
-        # it.)
-        self.assertNotIsInstance(app.logger,
-                                 flask_logging_extras.FlaskExtraLogger)
-
-        flask_logging_extras.register_logger_class()
-
-        # Even after registratiiion, existing apps are (obviously) not
-        # tampered with
-
-        self.assertNotIsInstance(app.logger,
-                                 flask_logging_extras.FlaskExtraLogger)
-
-        app = Flask('test_app')
-
-        # Newly created apps, though, should be made with this class
-        self.assertIsInstance(app.logger,
-                              flask_logging_extras.FlaskExtraLogger)
-
-    def _create_app_with_logger(self, fmt, keywords=[]):
-        app = Flask('test_app')
-
-        self.assertIsInstance(app.logger,
-                              flask_logging_extras.FlaskExtraLogger)
-
-        app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = keywords
-        app.logger.init_app(app)
-
-        formatter = logging.Formatter(fmt)
-        stream = ListStream()
-
-        handler = TestingStreamHandler(stream=stream)
-        handler.setLevel(logging.DEBUG)
-        handler.setFormatter(formatter)
-
-        app.logger.addHandler(handler)
-        app.logger.setLevel(logging.DEBUG)
-
-        return app, stream
-
-    def test_keywords(self):
-        # Register our logger class as the default
-        old_logger_class = flask_logging_extras.register_logger_class()
-
-        app, log_stream = self._create_app_with_logger('%(message)s')
-
-        app.logger.info('message')
-        # With the current formatter, the last log line must be a just the
-        # message
-        self.assertEqual(log_stream.lines[-1], 'message\n')
-
-        app, log_stream = self._create_app_with_logger(
-            '%(message)s %(extra_keyword)s')
-
-        # If we don’t register 'extra_keyword' in the app config, we get a
         # KeyError.  We set logging.raiseExceptions to False here; the
         # reason is that this doesn’t mean an actual exception is raised,
         # but our TestingStreamHandler does that for us (which we need for
         # testing purposes)
-        old_raiseExceptions = logging.raiseExceptions
+        """
-        logging.raiseExceptions = False
-        with self.assertRaises(KeyError):
-            app.logger.info('message')
-        logging.raiseExceptions = old_raiseExceptions
 
-        app, log_stream = self._create_app_with_logger(
+        with self.app.app_context():
-            '%(message)s [%(extra_keyword)s]',
+            self.logger.info('message', extra=dict(extra_keyword='test'))
-            keywords={'extra_keyword': '<unset>'})
 
-        app.logger.info('message', extra_keyword='test')
+        self.assertIn('message test', self.handler.logs)
-        self.assertEqual('message [test]\n', log_stream.lines[-1])
 
-        # If we don’t provide a value for a registered extra keyword, the
+    def test_keywords_app_ctx_no_value(self):
+        """If we don’t provide a value for a registered extra keyword, the
         # string "<unset>" will be assigned.
-        app.logger.info('message')
+        """
-        self.assertEqual('message [<unset>]\n', log_stream.lines[-1])
+
+        with self.app.app_context():
+            self.logger.info('message')
+
+        self.assertIn('message placeholder', self.handler.logs)
 
 
 class LoggerBlueprintTestCase(TestCase):
     def setUp(self):
         # Register our logger class
-        self.original_logger_class = logging.getLoggerClass()
-        flask_logging_extras.register_logger_class()
 
         app = Flask('test_app')
         self.app = app
-        app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = (
+        app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = ('bp', '<app>', '<norequest>')
-            'bp', '<app>', '<norequest>')
-        app.logger.init_app(app)
 
-        fmt = '%(bp)s %(message)s'
+        configure_loggers('bp')
-        self.stream = ListStream()
+        self.logger = logging.getLogger('selftest')
+        handlers = [handler for handler in self.logger.handlers if isinstance(handler, ListHandler)]
+        self.handler = handlers[0]
 
-        formatter = logging.Formatter(fmt)
+        bp = Blueprint('test_blueprint', 'test_bp')
-        self.handler = TestingStreamHandler(stream=self.stream)
-        self.handler.setLevel(logging.DEBUG)
-        self.handler.setFormatter(formatter)
-        app.logger.addHandler(self.handler)
-        app.logger.setLevel(logging.DEBUG)
-
-        bp = Blueprint('test_blueprint', 'test_bpg13')
 
         @app.route('/app')
         def route_1():
-            current_app.logger.info('Message')
+            self.logger.info('Message')
 
             return ''
 
         @bp.route('/blueprint')
         def route_2():
-            current_app.logger.info('Message')
+            self.logger.info('Message')
 
             return ''
 
@@ -215,26 +136,16 @@ class LoggerBlueprintTestCase(TestCase):
 
         self.client = app.test_client()
 
-    def tearDown(self):
+    def test_blueprint_log_no_blueprint(self):
-        logging.setLoggerClass(self.original_logger_class)
-
-    def test_autoconfig(self):
-        logger = logging.getLogger('test')
-        logger.addHandler(self.handler)
-
-        with self.app.app_context():
-            logger.warning('Hello')
-
-        self.assertEqual('<norequest> Hello\n', self.stream.lines[-1])
-
-    def test_request_log(self):
         self.client.get('/app')
-        self.assertEqual('<app> Message\n', self.stream.lines[-1])
+        self.assertIn('Message <app>', self.handler.logs)
 
-        page = self.client.get('/blueprint')
+    def test_blueprint_log_blueprint(self):
-        self.assertEqual('test_blueprint Message\n', self.stream.lines[-1])
+        self.client.get('/blueprint')
+        self.assertIn('Message test_blueprint', self.handler.logs)
 
+    def test_blueprint_log_no_request(self):
         with self.app.app_context():
-            current_app.logger.info('Message')
+            self.logger.info('Message')
 
-        self.assertEqual('<norequest> Message\n', self.stream.lines[-1])
+        self.assertIn('Message <norequest>', self.handler.logs)