2017-01-16 10:40:30 +00:00
|
|
|
|
# -*- coding: utf-8 -*-
|
2018-05-02 10:35:15 +00:00
|
|
|
|
"""Unit tests for Flask-Logging-Extras
|
2017-01-16 10:40:30 +00:00
|
|
|
|
"""
|
|
|
|
|
|
|
|
|
|
import logging
|
2018-05-02 10:35:15 +00:00
|
|
|
|
from logging.config import dictConfig
|
2017-01-16 10:40:30 +00:00
|
|
|
|
import sys
|
|
|
|
|
from unittest import TestCase
|
|
|
|
|
|
2017-02-02 15:33:14 +00:00
|
|
|
|
from flask import Flask, Blueprint, current_app
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
|
|
|
|
import flask_logging_extras
|
|
|
|
|
|
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
class ListHandler(logging.StreamHandler):
|
2017-01-16 10:40:30 +00:00
|
|
|
|
def __init__(self, *args, **kwargs):
|
2018-05-02 10:35:15 +00:00
|
|
|
|
super(ListHandler, self).__init__(*args, **kwargs)
|
|
|
|
|
|
|
|
|
|
self.logs = []
|
|
|
|
|
|
|
|
|
|
def emit(self, record):
|
|
|
|
|
try:
|
|
|
|
|
msg = self.format(record)
|
|
|
|
|
except (KeyError, IndexError) as exc:
|
|
|
|
|
msg = (exc.__class__.__name__, str(exc))
|
|
|
|
|
|
|
|
|
|
self.logs.append(msg)
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
def configure_loggers(extra_var):
|
|
|
|
|
dictConfig({
|
|
|
|
|
'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',
|
|
|
|
|
},
|
|
|
|
|
},
|
|
|
|
|
})
|
|
|
|
|
|
|
|
|
|
formatter = flask_logging_extras.FlaskExtraLoggerFormatter(
|
|
|
|
|
fmt='%(message)s %({extra_var})s'.format(extra_var=extra_var))
|
|
|
|
|
|
|
|
|
|
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
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
|
|
|
|
|
|
|
|
|
class LoggerKeywordsTestCase(TestCase):
|
|
|
|
|
def setUp(self):
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.logger, self.handler = configure_loggers('extra_keyword')
|
|
|
|
|
self.app = Flask('test_app')
|
|
|
|
|
self.app.config['FLASK_LOGGING_EXTRAS_KEYWORDS'] = {
|
|
|
|
|
'extra_keyword': 'placeholder',
|
|
|
|
|
}
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
# Make sure we don’t try to log the current blueprint for this test case
|
|
|
|
|
self.app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = (None, '', '')
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_keywords_no_app_ctx(self):
|
|
|
|
|
"""With the current formatter, the last log line must be a just the message
|
|
|
|
|
"""
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.logger.info('message')
|
|
|
|
|
self.assertIn(('KeyError', "'extra_keyword'"), self.handler.logs)
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_keywords_app_ctx_assign_value(self):
|
|
|
|
|
"""If we don’t register 'extra_keyword' in the app config, we get a
|
2017-01-16 10:40:30 +00:00
|
|
|
|
# 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)
|
2018-05-02 10:35:15 +00:00
|
|
|
|
"""
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
with self.app.app_context():
|
|
|
|
|
self.logger.info('message', extra=dict(extra_keyword='test'))
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.assertIn('message test', self.handler.logs)
|
2017-01-16 10:40:30 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_keywords_app_ctx_no_value(self):
|
|
|
|
|
"""If we don’t provide a value for a registered extra keyword, the
|
2017-01-16 10:40:30 +00:00
|
|
|
|
# string "<unset>" will be assigned.
|
2018-05-02 10:35:15 +00:00
|
|
|
|
"""
|
|
|
|
|
|
|
|
|
|
with self.app.app_context():
|
|
|
|
|
self.logger.info('message')
|
|
|
|
|
|
|
|
|
|
self.assertIn('message placeholder', self.handler.logs)
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
|
|
|
|
|
|
|
|
|
class LoggerBlueprintTestCase(TestCase):
|
|
|
|
|
def setUp(self):
|
|
|
|
|
# Register our logger class
|
|
|
|
|
|
|
|
|
|
app = Flask('test_app')
|
|
|
|
|
self.app = app
|
2018-05-02 10:35:15 +00:00
|
|
|
|
app.config['FLASK_LOGGING_EXTRAS_BLUEPRINT'] = ('bp', '<app>', '<norequest>')
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
configure_loggers('bp')
|
|
|
|
|
self.logger = logging.getLogger('selftest')
|
|
|
|
|
handlers = [handler for handler in self.logger.handlers if isinstance(handler, ListHandler)]
|
|
|
|
|
self.handler = handlers[0]
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
bp = Blueprint('test_blueprint', 'test_bp')
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
|
|
|
|
@app.route('/app')
|
|
|
|
|
def route_1():
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.logger.info('Message')
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
|
|
|
|
return ''
|
|
|
|
|
|
|
|
|
|
@bp.route('/blueprint')
|
|
|
|
|
def route_2():
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.logger.info('Message')
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
|
|
|
|
return ''
|
|
|
|
|
|
|
|
|
|
app.register_blueprint(bp)
|
|
|
|
|
|
|
|
|
|
self.client = app.test_client()
|
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_blueprint_log_no_blueprint(self):
|
2017-02-02 15:33:14 +00:00
|
|
|
|
self.client.get('/app')
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.assertIn('Message <app>', self.handler.logs)
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_blueprint_log_blueprint(self):
|
|
|
|
|
self.client.get('/blueprint')
|
|
|
|
|
self.assertIn('Message test_blueprint', self.handler.logs)
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
def test_blueprint_log_no_request(self):
|
2017-02-02 15:33:14 +00:00
|
|
|
|
with self.app.app_context():
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.logger.info('Message')
|
2017-02-02 15:33:14 +00:00
|
|
|
|
|
2018-05-02 10:35:15 +00:00
|
|
|
|
self.assertIn('Message <norequest>', self.handler.logs)
|