From 9983e847425621b5e474ae9da6822f1af0b0cc1f Mon Sep 17 00:00:00 2001 From: Armin Ronacher Date: Thu, 3 Jun 2010 16:21:23 +0200 Subject: [PATCH] Fixed after_request handlers being called twice in some cases and improved logging system --- CHANGES | 2 ++ flask.py | 57 ++++++++++++++++++++++++++++---------------- tests/flask_tests.py | 16 +++++++++---- 3 files changed, 51 insertions(+), 24 deletions(-) diff --git a/CHANGES b/CHANGES index ca066dad..0eb34dc1 100644 --- a/CHANGES +++ b/CHANGES @@ -16,6 +16,8 @@ Release date to be announced, codename to be selected. - test client has not the ability to preserve the request context for a little longer. This can also be used to trigger custom requests that do not pop the request stack for testing. +- because the Python standard library caches loggers, the name of + the logger is configurable now to better support unittests. Version 0.3.1 ------------- diff --git a/flask.py b/flask.py index f5d94fbe..8e78bea8 100644 --- a/flask.py +++ b/flask.py @@ -16,6 +16,7 @@ import mimetypes from datetime import datetime, timedelta from itertools import chain +from threading import Lock from jinja2 import Environment, PackageLoader, FileSystemLoader from werkzeug import Request as RequestBase, Response as ResponseBase, \ LocalStack, LocalProxy, create_environ, SharedDataMiddleware, \ @@ -50,6 +51,9 @@ try: except (ImportError, AttributeError): pkg_resources = None +# a lock used for logger initialization +_logger_lock = Lock() + class Request(RequestBase): """The request object used by default in flask. Remembers the @@ -839,6 +843,12 @@ class Flask(_PackageBoundObject): #: `USE_X_SENDFILE` configuration key. Defaults to `False`. use_x_sendfile = ConfigAttribute('USE_X_SENDFILE') + #: the name of the logger to use. By default the logger name is the + #: package name passed to the constructor. + #: + #: .. versionadded:: 0.4 + logger_name = ConfigAttribute('LOGGER_NAME') + #: the logging format used for the debug logger. This is only used when #: the application is in debug mode, otherwise the attached logging #: handler does the formatting. @@ -863,7 +873,8 @@ class Flask(_PackageBoundObject): 'SECRET_KEY': None, 'SESSION_COOKIE_NAME': 'session', 'PERMANENT_SESSION_LIFETIME': timedelta(days=31), - 'USE_X_SENDFILE': False + 'USE_X_SENDFILE': False, + 'LOGGER_NAME': None }) def __init__(self, import_name): @@ -874,6 +885,10 @@ class Flask(_PackageBoundObject): #: to load a config from files. self.config = Config(self.root_path, self.default_config) + #: prepare the deferred setup of the logger + self._logger = None + self.logger_name = self.import_name + #: a dictionary of all view functions registered. The keys will #: be function names which are also used to generate URLs and #: the values are the function objects themselves. @@ -952,7 +967,7 @@ class Flask(_PackageBoundObject): ) self.jinja_env.filters['tojson'] = _tojson_filter - @cached_property + @property def logger(self): """A :class:`logging.Logger` object for this application. The default configuration is to log to stderr if the application is @@ -965,17 +980,23 @@ class Flask(_PackageBoundObject): .. versionadded:: 0.3 """ - from logging import getLogger, StreamHandler, Formatter, DEBUG - class DebugHandler(StreamHandler): - def emit(x, record): - if self.debug: - StreamHandler.emit(x, record) - handler = DebugHandler() - handler.setLevel(DEBUG) - handler.setFormatter(Formatter(self.debug_log_format)) - logger = getLogger(self.import_name) - logger.addHandler(handler) - return logger + if self._logger and self._logger.name == self.logger_name: + return self._logger + with _logger_lock: + if self._logger and self._logger.name == self.logger_name: + return self._logger + from logging import getLogger, StreamHandler, Formatter, DEBUG + class DebugHandler(StreamHandler): + def emit(x, record): + if self.debug: + StreamHandler.emit(x, record) + handler = DebugHandler() + handler.setLevel(DEBUG) + handler.setFormatter(Formatter(self.debug_log_format)) + logger = getLogger(self.logger_name) + logger.addHandler(handler) + self._logger = logger + return logger def create_jinja_loader(self): """Creates the Jinja loader. By default just a package loader for @@ -1412,16 +1433,12 @@ class Flask(_PackageBoundObject): if rv is None: rv = self.dispatch_request() response = self.make_response(rv) + except Exception, e: + response = self.make_response(self.handle_exception(e)) + try: response = self.process_response(response) except Exception, e: response = self.make_response(self.handle_exception(e)) - try: - response = self.process_response(response) - except Exception, e: - self.logger.exception('after_request handler failed ' - 'to postprocess error response. ' - 'Depending on uncertain state?') - return response(environ, start_response) def request_context(self, environ): diff --git a/tests/flask_tests.py b/tests/flask_tests.py index 6fbc88a6..eccf68f3 100644 --- a/tests/flask_tests.py +++ b/tests/flask_tests.py @@ -288,11 +288,11 @@ class BasicFunctionalityTestCase(unittest.TestCase): assert len(called) == 1 def test_after_request_handler_error(self): - error_out = StringIO() + called = [] app = flask.Flask(__name__) - app.logger.addHandler(StreamHandler(error_out)) @app.after_request def after_request(response): + called.append(True) 1/0 return response @app.route('/') @@ -301,7 +301,7 @@ class BasicFunctionalityTestCase(unittest.TestCase): rv = app.test_client().get('/') assert rv.status_code == 500 assert 'Internal Server Error' in rv.data - assert 'after_request handler failed' in error_out.getvalue() + assert len(called) == 1 def test_error_handling(self): app = flask.Flask(__name__) @@ -707,6 +707,14 @@ class SendfileTestCase(unittest.TestCase): class LoggingTestCase(unittest.TestCase): + def test_logger_cache(self): + app = flask.Flask(__name__) + logger1 = app.logger + assert app.logger is logger1 + assert logger1.name == __name__ + app.logger_name = __name__ + '/test_logger_cache' + assert app.logger is not logger1 + def test_debug_log(self): app = flask.Flask(__name__) app.debug = True @@ -736,9 +744,9 @@ class LoggingTestCase(unittest.TestCase): assert False, 'debug log ate the exception' def test_exception_logging(self): - from logging import StreamHandler out = StringIO() app = flask.Flask(__name__) + app.logger_name = 'flask_tests/test_exception_logging' app.logger.addHandler(StreamHandler(out)) @app.route('/')